Support for the Linux 'perf report' and 'perf annotate' tools.

In this change, the support comes in two flavours:

--perf_jit_prof - outputs the files in a new perf format that only works with a
patched perf tool (patch obtained from Stephane Eranian). Both 'perf report' and
'perf annotate' are supported (the file format also contains the machine code).

--perf_basic_prof - outputs the files in a format that the existing perf tool
can consume. Only 'perf report' is supported.

In both cases, we have to disable code compaction because the perf tool does not
understand code relocation. (We are told that code relocation should be
supported soon.)

Usage:

perf record -g d8 --perf_jit_prof --no_compact_code_space my.js
perf report

The change itself is straightforward - we simply listen to code events and
write an entry to a log file for every new piece of code.

I am not yet sure whether we should keep both versions or just one (and which
one). My hope is the reviewers can help here.

R=danno@chromium.org
BUG=

Review URL: https://codereview.chromium.org/70013002

git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@18034 ce2b1a6d-e550-0410-aec6-3dcde31c8c00

src/flag-definitions.h

@@ -785,6 +785,10 @@ DEFINE_bool(log_regexp, false, "Log regular expression execution.")
 DEFINE_string(logfile, "v8.log", "Specify the name of the log file.")
 DEFINE_bool(logfile_per_isolate, true, "Separate log files for each isolate.")
 DEFINE_bool(ll_prof, false, "Enable low-level linux profiler.")
+DEFINE_bool(perf_basic_prof, false,
+            "Enable perf linux profiler (basic support).")
+DEFINE_bool(perf_jit_prof, false,
+            "Enable perf linux profiler (experimental annotate support).")
 DEFINE_string(gc_fake_mmap, "/tmp/__v8_gc__",
               "Specify the name of the file for fake gc mmap used in ll_prof")
 DEFINE_bool(log_internal_timer_events, false, "Time internal events.")

src/isolate.cc

@@ -2059,12 +2059,22 @@ bool Isolate::Init(Deserializer* des) {
   // If we are deserializing, log non-function code objects and compiled
   // functions found in the snapshot.
   if (!create_heap_objects &&
-      (FLAG_log_code || FLAG_ll_prof || logger_->is_logging_code_events())) {
+      (FLAG_log_code ||
+       FLAG_ll_prof ||
+       FLAG_perf_jit_prof ||
+       FLAG_perf_basic_prof ||
+       logger_->is_logging_code_events())) {
     HandleScope scope(this);
     LOG(this, LogCodeObjects());
     LOG(this, LogCompiledFunctions());
   }
 
+  // If we are profiling with the Linux perf tool, we need to disable
+  // code relocation.
+  if (FLAG_perf_jit_prof || FLAG_perf_basic_prof) {
+    FLAG_compact_code_space = false;
+  }
+
   CHECK_EQ(static_cast<int>(OFFSET_OF(Isolate, embedder_data_)),
            Internals::kIsolateEmbedderDataOffset);
   CHECK_EQ(static_cast<int>(OFFSET_OF(Isolate, heap_.roots_)),

src/log-utils.h

@@ -47,7 +47,8 @@ class Log {
   static bool InitLogAtStart() {
     return FLAG_log || FLAG_log_runtime || FLAG_log_api
         || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
-        || FLAG_log_regexp || FLAG_ll_prof || FLAG_log_internal_timer_events;
+        || FLAG_log_regexp || FLAG_ll_prof || FLAG_perf_basic_prof
+        || FLAG_perf_jit_prof || FLAG_log_internal_timer_events;
   }
 
   // Frees all resources acquired in Initialize and Open... functions.

src/log.cc

@@ -246,6 +246,231 @@ void CodeEventLogger::RegExpCodeCreateEvent(Code* code, String* source) {
 }
 
 
+// Linux perf tool logging support
+class PerfBasicLogger : public CodeEventLogger {
+ public:
+  PerfBasicLogger();
+  virtual ~PerfBasicLogger();
+
+  virtual void CodeMoveEvent(Address from, Address to) { }
+  virtual void CodeDeleteEvent(Address from) { }
+
+ private:
+  virtual void LogRecordedBuffer(Code* code,
+                                 SharedFunctionInfo* shared,
+                                 const char* name,
+                                 int length);
+
+  // Extension added to V8 log file name to get the low-level log name.
+  static const char kFilenameFormatString[];
+  static const int kFilenameBufferPadding;
+
+  // File buffer size of the low-level log. We don't use the default to
+  // minimize the associated overhead.
+  static const int kLogBufferSize = 2 * MB;
+
+  FILE* perf_output_handle_;
+};
+
+const char PerfBasicLogger::kFilenameFormatString[] = "/tmp/perf-%d.map";
+// Extra space for the PID in the filename
+const int PerfBasicLogger::kFilenameBufferPadding = 16;
+
+PerfBasicLogger::PerfBasicLogger()
+    : perf_output_handle_(NULL) {
+  // Open the perf JIT dump file.
+  int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
+  ScopedVector<char> perf_dump_name(bufferSize);
+  int size = OS::SNPrintF(
+      perf_dump_name,
+      kFilenameFormatString,
+      OS::GetCurrentProcessId());
+  CHECK_NE(size, -1);
+  perf_output_handle_ = OS::FOpen(perf_dump_name.start(), OS::LogFileOpenMode);
+  CHECK_NE(perf_output_handle_, NULL);
+  setvbuf(perf_output_handle_, NULL, _IOFBF, kLogBufferSize);
+}
+
+
+PerfBasicLogger::~PerfBasicLogger() {
+  fclose(perf_output_handle_);
+  perf_output_handle_ = NULL;
+}
+
+
+void PerfBasicLogger::LogRecordedBuffer(Code* code,
+                                       SharedFunctionInfo*,
+                                       const char* name,
+                                       int length) {
+  ASSERT(code->instruction_start() == code->address() + Code::kHeaderSize);
+
+  OS::FPrint(perf_output_handle_, "%llx %x %.*s\n",
+      reinterpret_cast<uint64_t>(code->instruction_start()),
+      code->instruction_size(),
+      length, name);
+}
+
+
+// Linux perf tool logging support
+class PerfJitLogger : public CodeEventLogger {
+ public:
+  PerfJitLogger();
+  virtual ~PerfJitLogger();
+
+  virtual void CodeMoveEvent(Address from, Address to) { }
+  virtual void CodeDeleteEvent(Address from) { }
+
+ private:
+  virtual void LogRecordedBuffer(Code* code,
+                                 SharedFunctionInfo* shared,
+                                 const char* name,
+                                 int length);
+
+  // Extension added to V8 log file name to get the low-level log name.
+  static const char kFilenameFormatString[];
+  static const int kFilenameBufferPadding;
+
+  // File buffer size of the low-level log. We don't use the default to
+  // minimize the associated overhead.
+  static const int kLogBufferSize = 2 * MB;
+
+  void LogWriteBytes(const char* bytes, int size);
+  void LogWriteHeader();
+
+  static const uint32_t kJitHeaderMagic = 0x4F74496A;
+  static const uint32_t kJitHeaderVersion = 0x2;
+  static const uint32_t kElfMachIA32 = 3;
+  static const uint32_t kElfMachX64 = 62;
+  static const uint32_t kElfMachARM = 40;
+  static const uint32_t kElfMachMIPS = 10;
+
+  struct jitheader {
+    uint32_t magic;
+    uint32_t version;
+    uint32_t total_size;
+    uint32_t elf_mach;
+    uint32_t pad1;
+    uint32_t pid;
+    uint64_t timestamp;
+  };
+
+  enum jit_record_type {
+    JIT_CODE_LOAD = 0
+    // JIT_CODE_UNLOAD = 1,
+    // JIT_CODE_CLOSE = 2,
+    // JIT_CODE_DEBUG_INFO = 3,
+    // JIT_CODE_PAGE_MAP = 4,
+    // JIT_CODE_MAX = 5
+  };
+
+  struct jr_code_load {
+    uint32_t id;
+    uint32_t total_size;
+    uint64_t timestamp;
+    uint64_t vma;
+    uint64_t code_addr;
+    uint32_t code_size;
+    uint32_t align;
+  };
+
+  uint32_t GetElfMach() {
+#if V8_TARGET_ARCH_IA32
+    return kElfMachIA32;
+#elif V8_TARGET_ARCH_X64
+    return kElfMachX64;
+#elif V8_TARGET_ARCH_ARM
+    return kElfMachARM;
+#elif V8_TARGET_ARCH_MIPS
+    return kElfMachMIPS;
+#else
+    UNIMPLEMENTED();
+    return 0;
+#endif
+  }
+
+  FILE* perf_output_handle_;
+};
+
+const char PerfJitLogger::kFilenameFormatString[] = "/tmp/jit-%d.dump";
+
+// Extra padding for the PID in the filename
+const int PerfJitLogger::kFilenameBufferPadding = 16;
+
+PerfJitLogger::PerfJitLogger()
+    : perf_output_handle_(NULL) {
+  // Open the perf JIT dump file.
+  int bufferSize = sizeof(kFilenameFormatString) + kFilenameBufferPadding;
+  ScopedVector<char> perf_dump_name(bufferSize);
+  int size = OS::SNPrintF(
+      perf_dump_name,
+      kFilenameFormatString,
+      OS::GetCurrentProcessId());
+  CHECK_NE(size, -1);
+  perf_output_handle_ = OS::FOpen(perf_dump_name.start(), OS::LogFileOpenMode);
+  CHECK_NE(perf_output_handle_, NULL);
+  setvbuf(perf_output_handle_, NULL, _IOFBF, kLogBufferSize);
+
+  LogWriteHeader();
+}
+
+
+PerfJitLogger::~PerfJitLogger() {
+  fclose(perf_output_handle_);
+  perf_output_handle_ = NULL;
+}
+
+
+void PerfJitLogger::LogRecordedBuffer(Code* code,
+                                      SharedFunctionInfo*,
+                                      const char* name,
+                                      int length) {
+  ASSERT(code->instruction_start() == code->address() + Code::kHeaderSize);
+  ASSERT(perf_output_handle_ != NULL);
+
+  const char* code_name = name;
+  uint8_t* code_pointer = reinterpret_cast<uint8_t*>(code->instruction_start());
+  uint32_t code_size = code->instruction_size();
+
+  static const char string_terminator[] = "\0";
+
+  jr_code_load code_load;
+  code_load.id = JIT_CODE_LOAD;
+  code_load.total_size = sizeof(code_load) + length + 1 + code_size;
+  code_load.timestamp =
+      static_cast<uint64_t>(OS::TimeCurrentMillis() * 1000.0);
+  code_load.vma = 0x0;  //  Our addresses are absolute.
+  code_load.code_addr = reinterpret_cast<uint64_t>(code->instruction_start());
+  code_load.code_size = code_size;
+  code_load.align = 0;
+
+  LogWriteBytes(reinterpret_cast<const char*>(&code_load), sizeof(code_load));
+  LogWriteBytes(code_name, length);
+  LogWriteBytes(string_terminator, 1);
+  LogWriteBytes(reinterpret_cast<const char*>(code_pointer), code_size);
+}
+
+
+void PerfJitLogger::LogWriteBytes(const char* bytes, int size) {
+  size_t rv = fwrite(bytes, 1, size, perf_output_handle_);
+  ASSERT(static_cast<size_t>(size) == rv);
+  USE(rv);
+}
+
+
+void PerfJitLogger::LogWriteHeader() {
+  ASSERT(perf_output_handle_ != NULL);
+  jitheader header;
+  header.magic = kJitHeaderMagic;
+  header.version = kJitHeaderVersion;
+  header.total_size = sizeof(jitheader);
+  header.pad1 = 0xdeadbeef;
+  header.elf_mach = GetElfMach();
+  header.pid = OS::GetCurrentProcessId();
+  header.timestamp = static_cast<uint64_t>(OS::TimeCurrentMillis() * 1000.0);
+  LogWriteBytes(reinterpret_cast<const char*>(&header), sizeof(header));
+}
+
+
 // Low-level logging support.
 #define LL_LOG(Call) if (ll_logger_) ll_logger_->Call;
 
@@ -711,6 +936,8 @@ Logger::Logger(Isolate* isolate)
     log_events_(NULL),
     is_logging_(false),
     log_(new Log(this)),
+    perf_basic_logger_(NULL),
+    perf_jit_logger_(NULL),
     ll_logger_(NULL),
     jit_logger_(NULL),
     listeners_(5),
@@ -1844,6 +2071,17 @@ bool Logger::SetUp(Isolate* isolate) {
       PrepareLogFileName(isolate, FLAG_logfile);
   log_->Initialize(*log_file_name);
 
+
+  if (FLAG_perf_basic_prof) {
+    perf_basic_logger_ = new PerfBasicLogger();
+    addCodeEventListener(perf_basic_logger_);
+  }
+
+  if (FLAG_perf_jit_prof) {
+    perf_jit_logger_ = new PerfJitLogger();
+    addCodeEventListener(perf_jit_logger_);
+  }
+
   if (FLAG_ll_prof) {
     ll_logger_ = new LowLevelLogger(*log_file_name);
     addCodeEventListener(ll_logger_);
@@ -1906,6 +2144,18 @@ FILE* Logger::TearDown() {
   delete ticker_;
   ticker_ = NULL;
 
+  if (perf_basic_logger_) {
+    removeCodeEventListener(perf_basic_logger_);
+    delete perf_basic_logger_;
+    perf_basic_logger_ = NULL;
+  }
+
+  if (perf_jit_logger_) {
+    removeCodeEventListener(perf_jit_logger_);
+    delete perf_jit_logger_;
+    perf_jit_logger_ = NULL;
+  }
+
   if (ll_logger_) {
     removeCodeEventListener(ll_logger_);
     delete ll_logger_;

src/log.h

@@ -154,7 +154,9 @@ struct TickSample;
 
 
 class JitLogger;
+class PerfBasicLogger;
 class LowLevelLogger;
+class PerfJitLogger;
 class Sampler;
 
 class Logger {
@@ -437,6 +439,8 @@ class Logger {
 
   bool is_logging_;
   Log* log_;
+  PerfBasicLogger* perf_basic_logger_;
+  PerfJitLogger* perf_jit_logger_;
   LowLevelLogger* ll_logger_;
   JitLogger* jit_logger_;
   List<CodeEventListener*> listeners_;