Early WIP: rr/sampling profiler hybrid

CMakeLists.txt

@@ -247,6 +247,7 @@ set(RR_SOURCES
   src/MagicSaveDataMonitor.cc
   src/MonitoredSharedMemory.cc
   src/Monkeypatcher.cc
+  src/PerfCommand.cc
   src/PerfCounters.cc
   src/ProcMemMonitor.cc
   src/PsCommand.cc

src/PerfCommand.cc

@@ -0,0 +1,65 @@
+/* -*- Mode: C++; tab-width: 8; c-basic-offset: 2; indent-tabs-mode: nil; -*- */
+
+#include <map>
+
+#include "Command.h"
+#include "TraceStream.h"
+#include "TraceTaskEvent.h"
+#include "main.h"
+#include "util.h"
+#include "Flags.h"
+
+using namespace std;
+
+namespace rr {
+
+class PerfCommand : public Command {
+public:
+  virtual int run(vector<string>& args);
+
+protected:
+  PerfCommand(const char* name, const char* help) : Command(name, help) {}
+
+  static PerfCommand singleton;
+};
+
+PerfCommand PerfCommand::singleton("perf", " rr perf [<trace_dir>]\n");
+
+
+static int perf(const string& trace_dir, FILE* out) {
+  TraceReader trace(trace_dir);
+
+  if (!probably_not_interactive(STDOUT_FILENO) && !Flags::get().force_things) {
+    fprintf(stderr, "Cowardly refusing to write binary data to a tty. "
+                    "Use -f to overwrite\n");
+    return 1;
+  }
+
+  // Write perf file header
+
+  // Write perf file data
+  ssize_t total_bytes_left = trace.total_perf_bytes();
+  while (trace.good() && total_bytes_left > 0) {
+    size_t to_read = min((ssize_t)0x1000, total_bytes_left);
+    auto data = trace.read_perf_records(to_read);
+    fwrite(data.data(), 1, data.size(), out);
+    total_bytes_left -= to_read;
+  }
+
+  return 0;
+};
+
+int PerfCommand::run(vector<string>& args) {
+  while (parse_global_option(args)) {
+  }
+
+  string trace_dir;
+  if (!parse_optional_trace_dir(args, &trace_dir)) {
+    print_help(stderr);
+    return 1;
+  }
+
+  return perf(trace_dir, stdout);
+}
+
+} // namespace rr

src/PerfCounters.cc

@@ -11,6 +11,7 @@
 #include <string.h>
 #include <sys/ioctl.h>
 #include <sys/syscall.h>
+#include <sys/mman.h>
 #include <unistd.h>
 
 #include <algorithm>
@@ -26,6 +27,7 @@ using namespace std;
 namespace rr {
 
 static bool attributes_initialized;
+static struct perf_event_attr samples_attr;
 static struct perf_event_attr ticks_attr;
 static struct perf_event_attr page_faults_attr;
 static struct perf_event_attr hw_interrupts_attr;
@@ -150,6 +152,33 @@ static void init_perf_event_attr(struct perf_event_attr* attr,
   attr->exclude_guest = 1;
 }
 
+static void check_sampling_limit() {
+  static bool checked = false;
+  if (checked)
+    return;
+  // Check perf event sample rate and print a helpful error message
+  {
+    char line[64];
+    int fd = open("/proc/sys/kernel/perf_event_max_sample_rate", O_RDONLY);
+    if (read(fd, line, sizeof(line)) > 0) {
+      assert(atoi(line) >= 4000 &&
+        "Make sure /proc/sys/kernel/perf_event_max_sample_rate is set high enough");
+    }
+    close(fd);
+  }
+}
+
+static void init_samples_event() {
+  memset(&rr::samples_attr, 0, sizeof(rr::samples_attr));
+  rr::samples_attr.type = PERF_TYPE_HARDWARE;
+  rr::samples_attr.size = sizeof(rr::samples_attr);
+  rr::samples_attr.config = PERF_COUNT_HW_CPU_CYCLES;
+  rr::samples_attr.sample_freq = 4000;
+  rr::samples_attr.freq = 1;
+  rr::samples_attr.sample_type = PERF_SAMPLE_IP|PERF_SAMPLE_TIME|PERF_SAMPLE_READ|PERF_SAMPLE_TID;
+  rr::samples_attr.read_format = PERF_FORMAT_GROUP;
+}
+
 static void init_attributes() {
   if (attributes_initialized) {
     return;
@@ -175,6 +204,7 @@ static void init_attributes() {
                        pmu->rinsn_cntr_event);
   init_perf_event_attr(&hw_interrupts_attr, PERF_TYPE_RAW,
                        pmu->hw_intr_cntr_event);
+  init_samples_event();
   // libpfm encodes the event with this bit set, so we'll do the
   // same thing.  Unclear if necessary.
   hw_interrupts_attr.exclude_hv = 1;
@@ -187,7 +217,8 @@ const struct perf_event_attr& PerfCounters::ticks_attr() {
   return rr::ticks_attr;
 }
 
-PerfCounters::PerfCounters(pid_t tid) : tid(tid), started(false) {
+PerfCounters::PerfCounters(pid_t tid) : tid(tid), started(false),
+    sampling_enabled(false) {
   init_attributes();
 }
 
@@ -211,36 +242,59 @@ static ScopedFd start_counter(pid_t tid, int group_fd,
   return fd;
 }
 
+static const int SAMPLE_MMAP_SIZE = (1+(1<<10))*PAGE_SIZE;
+void PerfCounters::samples_unmapper::operator()(void *ptr)
+{
+ munmap(ptr, SAMPLE_MMAP_SIZE);
+}
+
 void PerfCounters::reset(Ticks ticks_period) {
   assert(ticks_period >= 0);
 
-  stop();
-
-  struct perf_event_attr attr = rr::ticks_attr;
-  attr.sample_period = ticks_period;
-  fd_ticks = start_counter(tid, -1, &attr);
-
-  struct f_owner_ex own;
-  own.type = F_OWNER_TID;
-  own.pid = tid;
-  if (fcntl(fd_ticks, F_SETOWN_EX, &own)) {
-    FATAL() << "Failed to SETOWN_EX ticks event fd";
-  }
-  if (fcntl(fd_ticks, F_SETFL, O_ASYNC) ||
-      fcntl(fd_ticks, F_SETSIG, PerfCounters::TIME_SLICE_SIGNAL)) {
-    FATAL() << "Failed to make ticks counter ASYNC with sig"
-            << signal_name(PerfCounters::TIME_SLICE_SIGNAL);
-  }
+  if (!started) {
+    int group_fd = -1;
+    if (enable_sampling() && !samples_mmap) {
+      check_sampling_limit();
+      fd_samples = start_counter(tid, -1, &rr::samples_attr);
+      samples_mmap.reset(mmap(NULL, SAMPLE_MMAP_SIZE, PROT_READ|PROT_WRITE,
+        MAP_SHARED, fd_samples, 0));
+      if (samples_mmap.get() == MAP_FAILED) {
+        FATAL() << "Failed to map samples page";
+      }
+      group_fd = fd_samples;
+    }
+
+    struct perf_event_attr attr = rr::ticks_attr;
+    attr.sample_period = ticks_period;
+    fd_ticks = start_counter(tid, group_fd, &attr);
+    if (group_fd == -1)
+      group_fd = fd_ticks;
+
+    struct f_owner_ex own;
+    own.type = F_OWNER_TID;
+    own.pid = tid;
+    if (fcntl(fd_ticks, F_SETOWN_EX, &own)) {
+      FATAL() << "Failed to SETOWN_EX ticks event fd";
+    }
+    if (fcntl(fd_ticks, F_SETFL, O_ASYNC) ||
+        fcntl(fd_ticks, F_SETSIG, PerfCounters::TIME_SLICE_SIGNAL)) {
+      FATAL() << "Failed to make ticks counter ASYNC with sig"
+              << signal_name(PerfCounters::TIME_SLICE_SIGNAL);
+    }
 
-  if (extra_perf_counters_enabled()) {
-    int group_leader = fd_ticks;
-    fd_hw_interrupts = start_counter(tid, group_leader, &hw_interrupts_attr);
-    fd_instructions_retired =
-        start_counter(tid, group_leader, &instructions_retired_attr);
-    fd_page_faults = start_counter(tid, group_leader, &page_faults_attr);
+    if (extra_perf_counters_enabled()) {
+      fd_hw_interrupts = start_counter(tid, group_fd, &hw_interrupts_attr);
+      fd_instructions_retired =
+          start_counter(tid, group_fd, &instructions_retired_attr);
+      fd_page_faults = start_counter(tid, group_fd, &page_faults_attr);
+    }
+  } else {
+    ioctl(fd_ticks, PERF_EVENT_IOC_RESET);
+    ioctl(fd_ticks, PERF_EVENT_IOC_PERIOD, &ticks_period);
   }
-
+    
   started = true;
+  counting = true;
 }
 
 void PerfCounters::stop() {
@@ -263,7 +317,11 @@ static int64_t read_counter(ScopedFd& fd) {
 }
 
 Ticks PerfCounters::read_ticks() {
-  return started ? read_counter(fd_ticks) : 0;
+  //uint64_t period = UINT32_MAX;
+  uint64_t val = started ? read_counter(fd_ticks) : 0;
+  //ioctl(fd_ticks, PERF_EVENT_IOC_RESET);
+  //ioctl(fd_ticks, PERF_EVENT_IOC_PERIOD, &period);
+  return val;
 }
 
 PerfCounters::Extra PerfCounters::read_extra() {

src/PerfCounters.h

@@ -10,6 +10,7 @@
 #include <signal.h>
 #include <stdint.h>
 #include <sys/types.h>
+#include <memory>
 
 #include "ScopedFd.h"
 #include "Ticks.h"
@@ -42,6 +43,11 @@ class PerfCounters {
   // for experimentation, but aren't necessary for core functionality.
   static bool extra_perf_counters_enabled() { return false; }
 
+  // Change this to 'true' to enable sampling
+  bool enable_sampling() { return sampling_enabled; }
+
+  void set_sampling(bool sampling) { sampling_enabled = sampling; }
+
   /**
    * Reset all counter values to 0 and program the counters to send
    * TIME_SLICE_SIGNAL when 'ticks_period' tick events have elapsed. (In reality
@@ -81,14 +87,24 @@ class PerfCounters {
   Extra read_extra();
 
   static const struct perf_event_attr& ticks_attr();
+
+  struct samples_unmapper {
+   public:
+     void operator()(void *ptr);
+  };
+  std::unique_ptr<void,samples_unmapper> samples_mmap;
+
+  bool counting;
 
 private:
   pid_t tid;
+  ScopedFd fd_samples;
   ScopedFd fd_ticks;
   ScopedFd fd_page_faults;
   ScopedFd fd_hw_interrupts;
   ScopedFd fd_instructions_retired;
   bool started;
+  bool sampling_enabled;
 };
 
 } // namespace rr

src/RecordCommand.cc

@@ -58,7 +58,9 @@ RecordCommand RecordCommand::singleton(
     "                             just the initial process.\n"
     "  --ignore-nested            Directly start child process when running\n"
     "                             under nested rr recording, instead of\n"
-    "                             raising an error.\n");
+    "                             raising an error.\n"
+    "  --sample                   Record program-state samples at a fixed\n"
+    "                             time interval.");
 
 struct RecordFlags {
   vector<string> extra_env;
@@ -103,6 +105,8 @@ struct RecordFlags {
 
   /* Start child process directly if run under nested rr recording */
   bool ignore_nested;
+
+  bool do_sampling;
 
   RecordFlags()
       : max_ticks(Scheduler::DEFAULT_MAX_TICKS),
@@ -116,7 +120,8 @@ struct RecordFlags {
         always_switch(false),
         chaos(false),
         wait_for_all(false),
-        ignore_nested(false) {}
+        ignore_nested(false),
+        do_sampling(false) {}
 };
 
 static void parse_signal_name(ParsedOption& opt) {
@@ -148,6 +153,7 @@ static bool parse_record_arg(vector<string>& args, RecordFlags& flags) {
     { 1, "no-file-cloning", NO_PARAMETER },
     { 2, "syscall-buffer-size", HAS_PARAMETER },
     { 3, "ignore-nested", NO_PARAMETER },
+    { 4, "sample", NO_PARAMETER },
     { 'b', "force-syscall-buffer", NO_PARAMETER },
     { 'c', "num-cpu-ticks", HAS_PARAMETER },
     { 'h', "chaos", NO_PARAMETER },
@@ -205,6 +211,9 @@ static bool parse_record_arg(vector<string>& args, RecordFlags& flags) {
     case 3:
       flags.ignore_nested = true;
       break;
+    case 4:
+      flags.do_sampling = true;
+      break;
     case 's':
       flags.always_switch = true;
       break;
@@ -283,7 +292,8 @@ static WaitStatus record(const vector<string>& args, const RecordFlags& flags) {
   LOG(info) << "Start recording...";
 
   auto session = RecordSession::create(
-      args, flags.extra_env, flags.use_syscall_buffer, flags.bind_cpu);
+      args, flags.extra_env, flags.use_syscall_buffer, flags.bind_cpu,
+      flags.do_sampling);
   setup_session_from_flags(*session, flags);
 
   // Install signal handlers after creating the session, to ensure they're not

src/RecordSession.cc

@@ -1473,7 +1473,8 @@ static string lookup_by_path(const string& name) {
 
 /*static*/ RecordSession::shr_ptr RecordSession::create(
     const vector<string>& argv, const vector<string>& extra_env,
-    SyscallBuffering syscallbuf, BindCPU bind_cpu) {
+    SyscallBuffering syscallbuf, BindCPU bind_cpu,
+    bool do_sampling) {
   // The syscallbuf library interposes some critical
   // external symbols like XShmQueryExtension(), so we
   // preload it whether or not syscallbuf is enabled. Indicate here whether
@@ -1556,15 +1557,17 @@ static string lookup_by_path(const string& name) {
   env.push_back("MOZ_GDB_SLEEP=0");
 
   shr_ptr session(
-      new RecordSession(full_path, argv, env, syscallbuf, bind_cpu));
+      new RecordSession(full_path, argv, env, syscallbuf, bind_cpu, do_sampling));
   return session;
 }
 
 RecordSession::RecordSession(const std::string& exe_path,
                              const std::vector<std::string>& argv,
                              const std::vector<std::string>& envp,
-                             SyscallBuffering syscallbuf, BindCPU bind_cpu)
-    : trace_out(argv[0], choose_cpu(bind_cpu)),
+                             SyscallBuffering syscallbuf, BindCPU bind_cpu,
+                             bool do_sampling)
+    : do_sampling_(do_sampling),
+      trace_out(argv[0], choose_cpu(bind_cpu)),
       scheduler_(*this),
       ignore_sig(0),
       continue_through_sig(0),