Fix issue 553: function frame is skipped in profile when compare stub is called.

The problem appeared due to a fact that stubs doesn't create a stack
frame, reusing the stack frame of the caller function. When building
stack traces, the current function is retrieved from PC, and its
callees are retrieved by traversing the stack backwards. Thus, for
stubs, the stub itself was discovered via PC, and then stub's caller's
caller was retrieved from stack.

To fix this problem, a pointer to JSFunction object is now captured
from the topmost stack frame, and is saved into stack trace log
record. Then a simple heuristics is applied whether a referred
function should be added to decoded stack, or not, to avoid reporting
the same function twice (from PC and from the pointer.)

BUG=553
TEST=added to mjsunit/tools/tickprocessor

Review URL: http://codereview.chromium.org/546089

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

src/frames.h

@@ -607,11 +607,12 @@ class SafeStackFrameIterator BASE_EMBEDDED {
   void Advance();
   void Reset();
 
- private:
   static bool IsWithinBounds(
       Address low_bound, Address high_bound, Address addr) {
     return low_bound <= addr && addr <= high_bound;
   }
+
+ private:
   bool IsValidStackAddress(Address addr) const {
     return IsWithinBounds(low_bound_, high_bound_, addr);
   }

src/handles.cc

@@ -681,14 +681,18 @@ bool CompileLazyShared(Handle<SharedFunctionInfo> shared,
 bool CompileLazy(Handle<JSFunction> function, ClearExceptionFlag flag) {
   // Compile the source information to a code object.
   Handle<SharedFunctionInfo> shared(function->shared());
-  return CompileLazyShared(shared, flag, 0);
+  bool result = CompileLazyShared(shared, flag, 0);
+  LOG(FunctionCreateEvent(*function));
+  return result;
 }
 
 
 bool CompileLazyInLoop(Handle<JSFunction> function, ClearExceptionFlag flag) {
   // Compile the source information to a code object.
   Handle<SharedFunctionInfo> shared(function->shared());
-  return CompileLazyShared(shared, flag, 1);
+  bool result = CompileLazyShared(shared, flag, 1);
+  LOG(FunctionCreateEvent(*function));
+  return result;
 }
 
 OptimizedObjectForAddingMultipleProperties::

src/log.cc

@@ -155,6 +155,13 @@ void StackTracer::Trace(TickSample* sample) {
     return;
   }
 
+  const Address functionAddr =
+      sample->fp + JavaScriptFrameConstants::kFunctionOffset;
+  if (SafeStackFrameIterator::IsWithinBounds(sample->sp, js_entry_sp,
+                                             functionAddr)) {
+    sample->function = Memory::Address_at(functionAddr) - kHeapObjectTag;
+  }
+
   int i = 0;
   const Address callback = Logger::current_state_ != NULL ?
       Logger::current_state_->external_callback() : NULL;
@@ -162,11 +169,8 @@ void StackTracer::Trace(TickSample* sample) {
     sample->stack[i++] = callback;
   }
 
-  SafeStackTraceFrameIterator it(
-      reinterpret_cast<Address>(sample->fp),
-      reinterpret_cast<Address>(sample->sp),
-      reinterpret_cast<Address>(sample->sp),
-      js_entry_sp);
+  SafeStackTraceFrameIterator it(sample->fp, sample->sp,
+                                 sample->sp, js_entry_sp);
   while (!it.done() && i < TickSample::kMaxFramesCount) {
     sample->stack[i++] = it.frame()->pc();
     it.Advance();
@@ -837,14 +841,45 @@ void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
 
 void Logger::CodeMoveEvent(Address from, Address to) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  static Address prev_to_ = NULL;
+  MoveEventInternal(CODE_MOVE_EVENT, from, to);
+#endif
+}
+
+
+void Logger::CodeDeleteEvent(Address from) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+  DeleteEventInternal(CODE_DELETE_EVENT, from);
+#endif
+}
+
+
+void Logger::SnapshotPositionEvent(Address addr, int pos) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+  if (!Log::IsEnabled() || !FLAG_log_snapshot_positions) return;
+  LogMessageBuilder msg;
+  msg.Append("%s,", log_events_[SNAPSHOT_POSITION_EVENT]);
+  msg.AppendAddress(addr);
+  msg.Append(",%d", pos);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
+  msg.Append('\n');
+  msg.WriteToLogFile();
+#endif
+}
+
+
+void Logger::FunctionCreateEvent(JSFunction* function) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+  static Address prev_code = NULL;
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,", log_events_[CODE_MOVE_EVENT]);
-  msg.AppendAddress(from);
+  msg.Append("%s,", log_events_[FUNCTION_CREATION_EVENT]);
+  msg.AppendAddress(function->address());
   msg.Append(',');
-  msg.AppendAddress(to, prev_to_);
-  prev_to_ = to;
+  msg.AppendAddress(function->code()->address(), prev_code);
+  prev_code = function->code()->address();
   if (FLAG_compress_log) {
     ASSERT(compression_helper_ != NULL);
     if (!compression_helper_->HandleMessage(&msg)) return;
@@ -855,12 +890,32 @@ void Logger::CodeMoveEvent(Address from, Address to) {
 }
 
 
-void Logger::CodeDeleteEvent(Address from) {
+void Logger::FunctionMoveEvent(Address from, Address to) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
+  MoveEventInternal(FUNCTION_MOVE_EVENT, from, to);
+#endif
+}
+
+
+void Logger::FunctionDeleteEvent(Address from) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+  DeleteEventInternal(FUNCTION_DELETE_EVENT, from);
+#endif
+}
+
+
+void Logger::MoveEventInternal(LogEventsAndTags event,
+                               Address from,
+                               Address to) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+  static Address prev_to_ = NULL;
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,", log_events_[CODE_DELETE_EVENT]);
+  msg.Append("%s,", log_events_[event]);
   msg.AppendAddress(from);
+  msg.Append(',');
+  msg.AppendAddress(to, prev_to_);
+  prev_to_ = to;
   if (FLAG_compress_log) {
     ASSERT(compression_helper_ != NULL);
     if (!compression_helper_->HandleMessage(&msg)) return;
@@ -871,13 +926,12 @@ void Logger::CodeDeleteEvent(Address from) {
 }
 
 
-void Logger::SnapshotPositionEvent(Address addr, int pos) {
+void Logger::DeleteEventInternal(LogEventsAndTags event, Address from) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (!Log::IsEnabled() || !FLAG_log_snapshot_positions) return;
+  if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,", log_events_[SNAPSHOT_POSITION_EVENT]);
-  msg.AppendAddress(addr);
-  msg.Append(",%d", pos);
+  msg.Append("%s,", log_events_[event]);
+  msg.AppendAddress(from);
   if (FLAG_compress_log) {
     ASSERT(compression_helper_ != NULL);
     if (!compression_helper_->HandleMessage(&msg)) return;
@@ -1069,13 +1123,17 @@ void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
 void Logger::TickEvent(TickSample* sample, bool overflow) {
   if (!Log::IsEnabled() || !FLAG_prof) return;
   static Address prev_sp = NULL;
+  static Address prev_function = NULL;
   LogMessageBuilder msg;
   msg.Append("%s,", log_events_[TICK_EVENT]);
-  Address prev_addr = reinterpret_cast<Address>(sample->pc);
+  Address prev_addr = sample->pc;
   msg.AppendAddress(prev_addr);
   msg.Append(',');
-  msg.AppendAddress(reinterpret_cast<Address>(sample->sp), prev_sp);
-  prev_sp = reinterpret_cast<Address>(sample->sp);
+  msg.AppendAddress(sample->sp, prev_sp);
+  prev_sp = sample->sp;
+  msg.Append(',');
+  msg.AppendAddress(sample->function, prev_function);
+  prev_function = sample->function;
   msg.Append(",%d", static_cast<int>(sample->state));
   if (overflow) {
     msg.Append(",overflow");
@@ -1144,6 +1202,7 @@ void Logger::ResumeProfiler(int flags) {
       LOG(UncheckedStringEvent("profiler", "resume"));
       FLAG_log_code = true;
       LogCompiledFunctions();
+      LogFunctionObjects();
       LogAccessorCallbacks();
       if (!FLAG_sliding_state_window) ticker_->Start();
     }
@@ -1290,6 +1349,20 @@ void Logger::LogCompiledFunctions() {
 }
 
 
+void Logger::LogFunctionObjects() {
+  AssertNoAllocation no_alloc;
+  HeapIterator iterator;
+  while (iterator.has_next()) {
+    HeapObject* obj = iterator.next();
+    ASSERT(obj != NULL);
+    if (!obj->IsJSFunction()) continue;
+    JSFunction* jsf = JSFunction::cast(obj);
+    if (!jsf->is_compiled()) continue;
+    LOG(FunctionCreateEvent(jsf));
+  }
+}
+
+
 void Logger::LogAccessorCallbacks() {
   AssertNoAllocation no_alloc;
   HeapIterator iterator;

src/log.h

@@ -116,6 +116,9 @@ class VMState BASE_EMBEDDED {
   V(CODE_CREATION_EVENT,            "code-creation",          "cc")       \
   V(CODE_MOVE_EVENT,                "code-move",              "cm")       \
   V(CODE_DELETE_EVENT,              "code-delete",            "cd")       \
+  V(FUNCTION_CREATION_EVENT,        "function-creation",      "fc")       \
+  V(FUNCTION_MOVE_EVENT,            "function-move",          "fm")       \
+  V(FUNCTION_DELETE_EVENT,          "function-delete",        "fd")       \
   V(SNAPSHOT_POSITION_EVENT,        "snapshot-pos",           "sp")       \
   V(TICK_EVENT,                     "tick",                   "t")        \
   V(REPEAT_META_EVENT,              "repeat",                 "r")        \
@@ -224,6 +227,12 @@ class Logger {
   static void CodeMoveEvent(Address from, Address to);
   // Emits a code delete event.
   static void CodeDeleteEvent(Address from);
+  // Emits a function object create event.
+  static void FunctionCreateEvent(JSFunction* function);
+  // Emits a function move event.
+  static void FunctionMoveEvent(Address from, Address to);
+  // Emits a function delete event.
+  static void FunctionDeleteEvent(Address from);
 
   static void SnapshotPositionEvent(Address addr, int pos);
 
@@ -278,6 +287,8 @@ class Logger {
 
   // Logs all compiled functions found in the heap.
   static void LogCompiledFunctions();
+  // Logs all compiled JSFunction objects found in the heap.
+  static void LogFunctionObjects();
   // Logs all accessor callbacks found in the heap.
   static void LogAccessorCallbacks();
   // Used for logging stubs found in the snapshot.
@@ -299,6 +310,15 @@ class Logger {
                                     const char* name,
                                     Address entry_point);
 
+  // Internal configurable move event.
+  static void MoveEventInternal(LogEventsAndTags event,
+                                Address from,
+                                Address to);
+
+  // Internal configurable move event.
+  static void DeleteEventInternal(LogEventsAndTags event,
+                                  Address from);
+
   // Emits aliases for compressed messages.
   static void LogAliases();
 

src/mark-compact.cc

@@ -969,12 +969,6 @@ inline void EncodeForwardingAddressInPagedSpace(HeapObject* old_object,
 inline void IgnoreNonLiveObject(HeapObject* object) {}
 
 
-// A code deletion event is logged for non-live code objects.
-inline void LogNonLiveCodeObject(HeapObject* object) {
-  if (object->IsCode()) LOG(CodeDeleteEvent(object->address()));
-}
-
-
 // Function template that, given a range of addresses (eg, a semispace or a
 // paged space page), iterates through the objects in the range to clear
 // mark bits and compute and encode forwarding addresses.  As a side effect,
@@ -1122,10 +1116,7 @@ static void SweepSpace(PagedSpace* space, DeallocateFunction dealloc) {
           is_previous_alive = true;
         }
       } else {
-        if (object->IsCode()) {
-          // Notify the logger that compiled code has been collected.
-          LOG(CodeDeleteEvent(Code::cast(object)->address()));
-        }
+        MarkCompactCollector::ReportDeleteIfNeeded(object);
         if (is_previous_alive) {  // Transition from live to free.
           free_start = current;
           is_previous_alive = false;
@@ -1212,7 +1203,7 @@ void MarkCompactCollector::EncodeForwardingAddresses() {
       Heap::old_data_space());
 
   EncodeForwardingAddressesInPagedSpace<MCAllocateFromCodeSpace,
-                                        LogNonLiveCodeObject>(
+                                        ReportDeleteIfNeeded>(
       Heap::code_space());
 
   EncodeForwardingAddressesInPagedSpace<MCAllocateFromCellSpace,
@@ -1952,6 +1943,8 @@ int MarkCompactCollector::RelocateCodeObject(HeapObject* obj) {
     Code::cast(copied_to)->Relocate(new_addr - old_addr);
     // Notify the logger that compiled code has moved.
     LOG(CodeMoveEvent(old_addr, new_addr));
+  } else if (copied_to->IsJSFunction()) {
+    LOG(FunctionMoveEvent(old_addr, new_addr));
   }
 
   return obj_size;
@@ -2004,4 +1997,15 @@ void MarkCompactCollector::RebuildRSets() {
   Heap::RebuildRSets();
 }
 
+
+void MarkCompactCollector::ReportDeleteIfNeeded(HeapObject* obj) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+  if (obj->IsCode()) {
+    LOG(CodeDeleteEvent(obj->address()));
+  } else if (obj->IsJSFunction()) {
+    LOG(FunctionDeleteEvent(obj->address()));
+  }
+#endif
+}
+
 } }  // namespace v8::internal

src/mark-compact.h

@@ -115,6 +115,9 @@ class MarkCompactCollector: public AllStatic {
   static bool in_use() { return state_ > PREPARE_GC; }
 #endif
 
+  // Determine type of object and emit deletion log event.
+  static void ReportDeleteIfNeeded(HeapObject* obj);
+
  private:
 #ifdef DEBUG
   enum CollectorState {

src/platform-freebsd.cc

@@ -555,17 +555,17 @@ static void ProfilerSignalHandler(int signal, siginfo_t* info, void* context) {
     ucontext_t* ucontext = reinterpret_cast<ucontext_t*>(context);
     mcontext_t& mcontext = ucontext->uc_mcontext;
 #if V8_HOST_ARCH_IA32
-    sample.pc = mcontext.mc_eip;
-    sample.sp = mcontext.mc_esp;
-    sample.fp = mcontext.mc_ebp;
+    sample.pc = reinterpret_cast<Address>(mcontext.mc_eip);
+    sample.sp = reinterpret_cast<Address>(mcontext.mc_esp);
+    sample.fp = reinterpret_cast<Address>(mcontext.mc_ebp);
 #elif V8_HOST_ARCH_X64
-    sample.pc = mcontext.mc_rip;
-    sample.sp = mcontext.mc_rsp;
-    sample.fp = mcontext.mc_rbp;
+    sample.pc = reinterpret_cast<Address>(mcontext.mc_rip);
+    sample.sp = reinterpret_cast<Address>(mcontext.mc_rsp);
+    sample.fp = reinterpret_cast<Address>(mcontext.mc_rbp);
 #elif V8_HOST_ARCH_ARM
-    sample.pc = mcontext.mc_r15;
-    sample.sp = mcontext.mc_r13;
-    sample.fp = mcontext.mc_r11;
+    sample.pc = reinterpret_cast<Address>(mcontext.mc_r15);
+    sample.sp = reinterpret_cast<Address>(mcontext.mc_r13);
+    sample.fp = reinterpret_cast<Address>(mcontext.mc_r11);
 #endif
     active_sampler_->SampleStack(&sample);
   }

src/platform-linux.cc

@@ -707,23 +707,23 @@ static void ProfilerSignalHandler(int signal, siginfo_t* info, void* context) {
     ucontext_t* ucontext = reinterpret_cast<ucontext_t*>(context);
     mcontext_t& mcontext = ucontext->uc_mcontext;
 #if V8_HOST_ARCH_IA32
-    sample.pc = mcontext.gregs[REG_EIP];
-    sample.sp = mcontext.gregs[REG_ESP];
-    sample.fp = mcontext.gregs[REG_EBP];
+    sample.pc = reinterpret_cast<Address>(mcontext.gregs[REG_EIP]);
+    sample.sp = reinterpret_cast<Address>(mcontext.gregs[REG_ESP]);
+    sample.fp = reinterpret_cast<Address>(mcontext.gregs[REG_EBP]);
 #elif V8_HOST_ARCH_X64
-    sample.pc = mcontext.gregs[REG_RIP];
-    sample.sp = mcontext.gregs[REG_RSP];
-    sample.fp = mcontext.gregs[REG_RBP];
+    sample.pc = reinterpret_cast<Address>(mcontext.gregs[REG_RIP]);
+    sample.sp = reinterpret_cast<Address>(mcontext.gregs[REG_RSP]);
+    sample.fp = reinterpret_cast<Address>(mcontext.gregs[REG_RBP]);
 #elif V8_HOST_ARCH_ARM
 // An undefined macro evaluates to 0, so this applies to Android's Bionic also.
 #if (__GLIBC__ < 2 || (__GLIBC__ == 2 && __GLIBC_MINOR__ <= 3))
-    sample.pc = mcontext.gregs[R15];
-    sample.sp = mcontext.gregs[R13];
-    sample.fp = mcontext.gregs[R11];
+    sample.pc = reinterpret_cast<Address>(mcontext.gregs[R15]);
+    sample.sp = reinterpret_cast<Address>(mcontext.gregs[R13]);
+    sample.fp = reinterpret_cast<Address>(mcontext.gregs[R11]);
 #else
-    sample.pc = mcontext.arm_pc;
-    sample.sp = mcontext.arm_sp;
-    sample.fp = mcontext.arm_fp;
+    sample.pc = reinterpret_cast<Address>(mcontext.arm_pc);
+    sample.sp = reinterpret_cast<Address>(mcontext.arm_sp);
+    sample.fp = reinterpret_cast<Address>(mcontext.arm_fp);
 #endif
 #endif
     if (IsVmThread())

src/platform-macos.cc

@@ -559,9 +559,9 @@ class Sampler::PlatformData : public Malloced {
                              flavor,
                              reinterpret_cast<natural_t*>(&state),
                              &count) == KERN_SUCCESS) {
-          sample.pc = state.REGISTER_FIELD(ip);
-          sample.sp = state.REGISTER_FIELD(sp);
-          sample.fp = state.REGISTER_FIELD(bp);
+          sample.pc = reinterpret_cast<Address>(state.REGISTER_FIELD(ip));
+          sample.sp = reinterpret_cast<Address>(state.REGISTER_FIELD(sp));
+          sample.fp = reinterpret_cast<Address>(state.REGISTER_FIELD(bp));
           sampler_->SampleStack(&sample);
         }
         thread_resume(profiled_thread_);

src/platform-win32.cc

@@ -1813,13 +1813,13 @@ class Sampler::PlatformData : public Malloced {
         context.ContextFlags = CONTEXT_FULL;
         if (GetThreadContext(profiled_thread_, &context) != 0) {
 #if V8_HOST_ARCH_X64
-          sample.pc = context.Rip;
-          sample.sp = context.Rsp;
-          sample.fp = context.Rbp;
+          sample.pc = reinterpret_cast<Address>(context.Rip);
+          sample.sp = reinterpret_cast<Address>(context.Rsp);
+          sample.fp = reinterpret_cast<Address>(context.Rbp);
 #else
-          sample.pc = context.Eip;
-          sample.sp = context.Esp;
-          sample.fp = context.Ebp;
+          sample.pc = reinterpret_cast<Address>(context.Eip);
+          sample.sp = reinterpret_cast<Address>(context.Esp);
+          sample.fp = reinterpret_cast<Address>(context.Ebp);
 #endif
           sampler_->SampleStack(&sample);
         }

src/platform.h

@@ -506,11 +506,18 @@ class Socket {
 // TickSample captures the information collected for each sample.
 class TickSample {
  public:
-  TickSample() : pc(0), sp(0), fp(0), state(OTHER), frames_count(0) {}
-  uintptr_t pc;  // Instruction pointer.
-  uintptr_t sp;  // Stack pointer.
-  uintptr_t fp;  // Frame pointer.
-  StateTag state;   // The state of the VM.
+  TickSample()
+      : pc(NULL),
+        sp(NULL),
+        fp(NULL),
+        function(NULL),
+        state(OTHER),
+        frames_count(0) {}
+  Address pc;  // Instruction pointer.
+  Address sp;  // Stack pointer.
+  Address fp;  // Frame pointer.
+  Address function;  // The last called JS function.
+  StateTag state;  // The state of the VM.
   static const int kMaxFramesCount = 100;
   EmbeddedVector<Address, kMaxFramesCount> stack;  // Call stack.
   int frames_count;  // Number of captured frames.

src/runtime.cc

@@ -4830,6 +4830,7 @@ static Object* Runtime_NewObject(Arguments args) {
     CompileLazyShared(Handle<SharedFunctionInfo>(function->shared()),
                                                  CLEAR_EXCEPTION,
                                                  0);
+    LOG(FunctionCreateEvent(*function));
   }
 
   bool first_allocation = !function->has_initial_map();

src/spaces.cc

@@ -2718,9 +2718,7 @@ void LargeObjectSpace::FreeUnmarkedObjects() {
       }
 
       // Free the chunk.
-      if (object->IsCode()) {
-        LOG(CodeDeleteEvent(object->address()));
-      }
+      MarkCompactCollector::ReportDeleteIfNeeded(object);
       size_ -= static_cast<int>(chunk_size);
       page_count_--;
       MemoryAllocator::FreeRawMemory(chunk_address, chunk_size);

test/cctest/test-log-stack-tracer.cc

@@ -47,10 +47,10 @@ static void InitTraceEnv(TickSample* sample) {
 
 
 static void DoTrace(Address fp) {
-  trace_env.sample->fp = reinterpret_cast<uintptr_t>(fp);
+  trace_env.sample->fp = fp;
   // sp is only used to define stack high bound
   trace_env.sample->sp =
-      reinterpret_cast<uintptr_t>(trace_env.sample) - 10240;
+      reinterpret_cast<Address>(trace_env.sample) - 10240;
   StackTracer::Trace(trace_env.sample);
 }
 

test/cctest/test-log.cc

@@ -202,9 +202,9 @@ static int CheckThatProfilerWorks(int log_pos) {
   // Force compiler to generate new code by parametrizing source.
   EmbeddedVector<char, 100> script_src;
   i::OS::SNPrintF(script_src,
-                  "for (var i = 0; i < 1000; ++i) { "
-                  "(function(x) { return %d * x; })(i); }",
-                  log_pos);
+                  "function f%d(x) { return %d * x; }"
+                  "for (var i = 0; i < 10000; ++i) { f%d(i); }",
+                  log_pos, log_pos, log_pos);
   // Run code for 200 msecs to get some ticks.
   const double end_time = i::OS::TimeCurrentMillis() + 200;
   while (i::OS::TimeCurrentMillis() < end_time) {
@@ -228,6 +228,7 @@ static int CheckThatProfilerWorks(int log_pos) {
   log_pos += log_size;
   // Check buffer contents.
   buffer[log_size] = '\0';
+  printf("%s", buffer.start());
   const char* tick = "\ntick,";
   CHECK_NE(NULL, strstr(buffer.start(), code_creation));
   const bool ticks_found = strstr(buffer.start(), tick) != NULL;

test/mjsunit/tools/logreader.js

@@ -67,7 +67,7 @@
   var reader = new devtools.profiler.LogReader({});
 
   assertEquals([0x10000000, 0x10001000, 0xffff000, 0x10000000],
-               reader.processStack(0x10000000, ['overflow',
+               reader.processStack(0x10000000, 0, ['overflow',
                    '+1000', '-2000', '+1000']));
 })();
 

test/mjsunit/tools/tickprocessor-test-func-info.log

+shared-library,"shell",0x08048000,0x081ee000
+shared-library,"/lib32/libm-2.7.so",0xf7db6000,0xf7dd9000
+shared-library,"ffffe000-fffff000",0xffffe000,0xfffff000
+profiler,"begin",1
+code-creation,Stub,0x424260,348,"CompareStub_GE"
+code-creation,LazyCompile,0x2a8100,18535,"DrawQube 3d-cube.js:188"
+function-creation,0x2d11b8,0x2a8100
+code-creation,LazyCompile,0x480100,3908,"DrawLine 3d-cube.js:17"
+function-creation,0x2d0f7c,0x480100
+tick,0x424284,0xbfffeea0,0x2d0f7c,0,0x2aaaa5
+tick,0x42429f,0xbfffed88,0x2d0f7c,0,0x2aacb4
+tick,0x48063d,0xbfffec7c,0x2d0f7c,0,0x2aaec6
+profiler,"end"

test/mjsunit/tools/tickprocessor-test.func-info

+Statistical profiling result from v8.log, (3 ticks, 0 unaccounted, 0 excluded).
+
+ [Shared libraries]:
+   ticks  total  nonlib   name
+
+ [JavaScript]:
+   ticks  total  nonlib   name
+      2   66.7%   66.7%  Stub: CompareStub_GE
+      1   33.3%   33.3%  LazyCompile: DrawLine 3d-cube.js:17
+
+ [C++]:
+   ticks  total  nonlib   name
+
+ [GC]:
+   ticks  total  nonlib   name
+      0    0.0%
+
+ [Bottom up (heavy) profile]:
+  Note: percentage shows a share of a particular caller in the total
+  amount of its parent calls.
+  Callers occupying less than 2.0% are not shown.
+
+   ticks parent  name
+      2   66.7%  Stub: CompareStub_GE
+      2  100.0%    LazyCompile: DrawLine 3d-cube.js:17
+      2  100.0%      LazyCompile: DrawQube 3d-cube.js:188
+
+      1   33.3%  LazyCompile: DrawLine 3d-cube.js:17
+      1  100.0%    LazyCompile: DrawQube 3d-cube.js:188

test/mjsunit/tools/tickprocessor-test.log

@@ -6,19 +6,20 @@ code-creation,Stub,0xf540a100,474,"CEntryStub"
 code-creation,Script,0xf541cd80,736,"exp.js"
 code-creation,Stub,0xf541d0e0,47,"RuntimeStub_Math_exp"
 code-creation,LazyCompile,0xf541d120,145,"exp native math.js:41"
+function-creation,0xf441d280,0xf541d120
 code-creation,LoadIC,0xf541d280,117,"j"
 code-creation,LoadIC,0xf541d360,63,"i"
-tick,0x80f82d1,0xffdfe880,0,0xf541ce5c
-tick,0x80f89a1,0xffdfecf0,0,0xf541ce5c
-tick,0x8123b5c,0xffdff1a0,0,0xf541d1a1,0xf541ceea
-tick,0x8123b65,0xffdff1a0,0,0xf541d1a1,0xf541ceea
-tick,0xf541d2be,0xffdff1e4,0
-tick,0xf541d320,0xffdff1dc,0
-tick,0xf541d384,0xffdff1d8,0
-tick,0xf7db94da,0xffdff0ec,0,0xf541d1a1,0xf541ceea
-tick,0xf7db951c,0xffdff0f0,0,0xf541d1a1,0xf541ceea
-tick,0xf7dbc508,0xffdff14c,0,0xf541d1a1,0xf541ceea
-tick,0xf7dbff21,0xffdff198,0,0xf541d1a1,0xf541ceea
-tick,0xf7edec90,0xffdff0ec,0,0xf541d1a1,0xf541ceea
-tick,0xffffe402,0xffdff488,0
+tick,0x80f82d1,0xffdfe880,0,0,0xf541ce5c
+tick,0x80f89a1,0xffdfecf0,0,0,0xf541ce5c
+tick,0x8123b5c,0xffdff1a0,0,0,0xf541d1a1,0xf541ceea
+tick,0x8123b65,0xffdff1a0,0,0,0xf541d1a1,0xf541ceea
+tick,0xf541d2be,0xffdff1e4,0,0
+tick,0xf541d320,0xffdff1dc,0,0
+tick,0xf541d384,0xffdff1d8,0,0
+tick,0xf7db94da,0xffdff0ec,0,0,0xf541d1a1,0xf541ceea
+tick,0xf7db951c,0xffdff0f0,0,0,0xf541d1a1,0xf541ceea
+tick,0xf7dbc508,0xffdff14c,0,0,0xf541d1a1,0xf541ceea
+tick,0xf7dbff21,0xffdff198,0,0,0xf541d1a1,0xf541ceea
+tick,0xf7edec90,0xffdff0ec,0,0,0xf541d1a1,0xf541ceea
+tick,0xffffe402,0xffdff488,0,0
 profiler,"end"

test/mjsunit/tools/tickprocessor.js

@@ -334,7 +334,7 @@ function PrintMonitor(outputOrFileName) {
   print = function(str) {
     var strSplit = str.split('\n');
     for (var i = 0; i < strSplit.length; ++i) {
-      s = strSplit[i];
+      var s = strSplit[i];
       realOut.push(s);
       if (outputPos < expectedOut.length) {
         if (expectedOut[outputPos] != s) {
@@ -400,7 +400,10 @@ function driveTickProcessorTest(
       'tickprocessor-test.log', 'tickprocessor-test.ignore-unknown'],
     'GcState': [
       false, false, TickProcessor.VmStates.GC,
-      'tickprocessor-test.log', 'tickprocessor-test.gc-state']
+      'tickprocessor-test.log', 'tickprocessor-test.gc-state'],
+    'FunctionInfo': [
+      false, false, null,
+      'tickprocessor-test-func-info.log', 'tickprocessor-test.func-info']
   };
   for (var testName in testData) {
     print('=== testProcessing-' + testName + ' ===');

tools/codemap.js

@@ -195,6 +195,18 @@ devtools.profiler.CodeMap.prototype.findEntry = function(addr) {
 };
 
 
+/**
+ * Returns a dynamic code entry using its starting address.
+ *
+ * @param {number} addr Address.
+ */
+devtools.profiler.CodeMap.prototype.findDynamicEntryByStartAddress =
+    function(addr) {
+  var node = this.dynamics_.find(addr);
+  return node ? node.value : null;
+};
+
+
 /**
  * Returns an array of all dynamic code entries.
  */

tools/logreader.js

@@ -139,11 +139,12 @@ devtools.profiler.LogReader.prototype.processLogChunk = function(chunk) {
  * Processes stack record.
  *
  * @param {number} pc Program counter.
+ * @param {number} func JS Function.
  * @param {Array.<string>} stack String representation of a stack.
  * @return {Array.<number>} Processed stack.
  */
-devtools.profiler.LogReader.prototype.processStack = function(pc, stack) {
-  var fullStack = [pc];
+devtools.profiler.LogReader.prototype.processStack = function(pc, func, stack) {
+  var fullStack = func ? [pc, func] : [pc];
   var prevFrame = pc;
   for (var i = 0, n = stack.length; i < n; ++i) {
     var frame = stack[i];

tools/profile.js

@@ -43,6 +43,11 @@ devtools.profiler.Profile = function() {
   this.bottomUpTree_ = new devtools.profiler.CallTree();
 };
 
+/**
+ * Version of profiler log.
+ */
+devtools.profiler.Profile.VERSION = 2;
+
 
 /**
  * Returns whether a function with the specified name must be skipped.
@@ -133,6 +138,21 @@ devtools.profiler.Profile.prototype.addCode = function(
 };
 
 
+/**
+ * Creates an alias entry for a code entry.
+ *
+ * @param {number} aliasAddr Alias address.
+ * @param {number} addr Code entry address.
+ */
+devtools.profiler.Profile.prototype.addCodeAlias = function(
+    aliasAddr, addr) {
+  var entry = this.codeMap_.findDynamicEntryByStartAddress(addr);
+  if (entry) {
+    this.codeMap_.addCode(aliasAddr, entry);
+  }
+};
+
+
 /**
  * Reports about moving of a dynamic code entry.
  *
@@ -162,6 +182,31 @@ devtools.profiler.Profile.prototype.deleteCode = function(start) {
 };
 
 
+/**
+ * Reports about moving of a dynamic code entry.
+ *
+ * @param {number} from Current code entry address.
+ * @param {number} to New code entry address.
+ */
+devtools.profiler.Profile.prototype.safeMoveDynamicCode = function(from, to) {
+  if (this.codeMap_.findDynamicEntryByStartAddress(from)) {
+    this.codeMap_.moveCode(from, to);
+  }
+};
+
+
+/**
+ * Reports about deletion of a dynamic code entry.
+ *
+ * @param {number} start Starting address.
+ */
+devtools.profiler.Profile.prototype.safeDeleteDynamicCode = function(start) {
+  if (this.codeMap_.findDynamicEntryByStartAddress(start)) {
+    this.codeMap_.deleteCode(start);
+  }
+};
+
+
 /**
  * Retrieves a code entry by an address.
  *
@@ -362,6 +407,13 @@ devtools.profiler.Profile.DynamicCodeEntry.prototype.getRawName = function() {
 };
 
 
+devtools.profiler.Profile.DynamicCodeEntry.prototype.isJSFunction = function() {
+  return this.type == "Function" ||
+    this.type == "LazyCompile" ||
+    this.type == "Script";
+};
+
+
 /**
  * Constructs a call graph.
  *

tools/tickprocessor.js

@@ -137,10 +137,19 @@ function TickProcessor(
           processor: this.processCodeMove, backrefs: true },
       'code-delete': { parsers: [this.createAddressParser('code')],
           processor: this.processCodeDelete, backrefs: true },
+      'function-creation': { parsers: [this.createAddressParser('code'),
+          this.createAddressParser('function-obj')],
+          processor: this.processFunctionCreation, backrefs: true },
+      'function-move': { parsers: [this.createAddressParser('code'),
+          this.createAddressParser('code-move-to')],
+          processor: this.processFunctionMove, backrefs: true },
+      'function-delete': { parsers: [this.createAddressParser('code')],
+          processor: this.processFunctionDelete, backrefs: true },
       'snapshot-pos': { parsers: [this.createAddressParser('code'), parseInt],
           processor: this.processSnapshotPosition, backrefs: true },
       'tick': { parsers: [this.createAddressParser('code'),
-          this.createAddressParser('stack'), parseInt, 'var-args'],
+          this.createAddressParser('stack'),
+          this.createAddressParser('func'), parseInt, 'var-args'],
           processor: this.processTick, backrefs: true },
       'heap-sample-begin': { parsers: [null, null, parseInt],
           processor: this.processHeapSampleBegin },
@@ -287,6 +296,22 @@ TickProcessor.prototype.processCodeDelete = function(start) {
 };
 
 
+TickProcessor.prototype.processFunctionCreation = function(
+    functionAddr, codeAddr) {
+  this.profile_.addCodeAlias(functionAddr, codeAddr);
+};
+
+
+TickProcessor.prototype.processFunctionMove = function(from, to) {
+  this.profile_.safeMoveDynamicCode(from, to);
+};
+
+
+TickProcessor.prototype.processFunctionDelete = function(start) {
+  this.profile_.safeDeleteDynamicCode(start);
+};
+
+
 TickProcessor.prototype.processSnapshotPosition = function(addr, pos) {
   if (this.snapshotLogProcessor_) {
     this.deserializedEntriesNames_[addr] =
@@ -300,7 +325,7 @@ TickProcessor.prototype.includeTick = function(vmState) {
 };
 
 
-TickProcessor.prototype.processTick = function(pc, sp, vmState, stack) {
+TickProcessor.prototype.processTick = function(pc, sp, func, vmState, stack) {
   this.ticks_.total++;
   if (vmState == TickProcessor.VmStates.GC) this.ticks_.gc++;
   if (!this.includeTick(vmState)) {
@@ -308,7 +333,19 @@ TickProcessor.prototype.processTick = function(pc, sp, vmState, stack) {
     return;
   }
 
-  this.profile_.recordTick(this.processStack(pc, stack));
+  if (func) {
+    var funcEntry = this.profile_.findEntry(func);
+    if (!funcEntry || !funcEntry.isJSFunction || !funcEntry.isJSFunction()) {
+      func = 0;
+    } else {
+      var currEntry = this.profile_.findEntry(pc);
+      if (!currEntry || !currEntry.isJSFunction || currEntry.isJSFunction()) {
+        func = 0;
+      }
+    }
+  }
+
+  this.profile_.recordTick(this.processStack(pc, func, stack));
 };
 
 
@@ -341,7 +378,7 @@ TickProcessor.prototype.processJSProducer = function(constructor, stack) {
   if (stack.length == 0) return;
   var first = stack.shift();
   var processedStack =
-      this.profile_.resolveAndFilterFuncs_(this.processStack(first, stack));
+      this.profile_.resolveAndFilterFuncs_(this.processStack(first, 0, stack));
   processedStack.unshift(constructor);
   this.currentProducerProfile_.addPath(processedStack);
 };

tools/tickprocessor.py

@@ -59,6 +59,8 @@ class CodeEntry(object):
   def IsICEntry(self):
     return False
 
+  def IsJSFunction(self):
+    return False
 
 class SharedLibraryEntry(CodeEntry):
 
@@ -124,6 +126,8 @@ class JSCodeEntry(CodeEntry):
     return self.type in ('CallIC', 'LoadIC', 'StoreIC') or \
       (self.type == 'Builtin' and self.builtin_ic_re.match(self.name))
 
+  def IsJSFunction(self):
+    return self.type in ('Function', 'LazyCompile', 'Script')
 
 class CodeRegion(object):
 
@@ -212,13 +216,19 @@ class TickProcessor(object):
         for row in logreader:
           row_num += 1
           if row[0] == 'tick':
-            self.ProcessTick(int(row[1], 16), int(row[2], 16), int(row[3]), self.PreprocessStack(row[4:]))
+            self.ProcessTick(int(row[1], 16), int(row[2], 16), int(row[3], 16), int(row[4]), self.PreprocessStack(row[5:]))
           elif row[0] == 'code-creation':
             self.ProcessCodeCreation(row[1], int(row[2], 16), int(row[3]), row[4])
           elif row[0] == 'code-move':
             self.ProcessCodeMove(int(row[1], 16), int(row[2], 16))
           elif row[0] == 'code-delete':
             self.ProcessCodeDelete(int(row[1], 16))
+          elif row[0] == 'function-creation':
+            self.ProcessFunctionCreation(int(row[1], 16), int(row[2], 16))
+          elif row[0] == 'function-move':
+            self.ProcessFunctionMove(int(row[1], 16), int(row[2], 16))
+          elif row[0] == 'function-delete':
+            self.ProcessFunctionDelete(int(row[1], 16))
           elif row[0] == 'shared-library':
             self.AddSharedLibraryEntry(row[1], int(row[2], 16), int(row[3], 16))
             self.ParseVMSymbols(row[1], int(row[2], 16), int(row[3], 16))
@@ -275,6 +285,27 @@ class TickProcessor(object):
     except splaytree.KeyNotFoundError:
       print('Code delete event for unknown code: 0x%x' % from_addr)
 
+  def ProcessFunctionCreation(self, func_addr, code_addr):
+    js_entry_node = self.js_entries.Find(code_addr)
+    if js_entry_node:
+      js_entry = js_entry_node.value
+      self.js_entries.Insert(func_addr, JSCodeEntry(func_addr, js_entry.name, js_entry.type, 1, None))
+
+  def ProcessFunctionMove(self, from_addr, to_addr):
+    try:
+      removed_node = self.js_entries.Remove(from_addr)
+      removed_node.value.SetStartAddress(to_addr);
+      self.js_entries.Insert(to_addr, removed_node.value)
+    except splaytree.KeyNotFoundError:
+      return
+
+  def ProcessFunctionDelete(self, from_addr):
+    try:
+      removed_node = self.js_entries.Remove(from_addr)
+      self.deleted_code.append(removed_node.value)
+    except splaytree.KeyNotFoundError:
+      return
+
   def ProcessBeginCodeRegion(self, id, assm, start, name):
     if not assm in self.pending_assemblers:
       self.pending_assemblers[assm] = Assembler()
@@ -320,7 +351,7 @@ class TickProcessor(object):
         result.append(entry.ToString())
     return result
 
-  def ProcessTick(self, pc, sp, state, stack):
+  def ProcessTick(self, pc, sp, func, state, stack):
     if state == VMStates['GC']:
       self.number_of_gc_ticks += 1
     if not self.IncludeTick(pc, sp, state):
@@ -337,11 +368,16 @@ class TickProcessor(object):
       if len(stack) > 0:
         caller_pc = stack.pop(0)
         self.total_number_of_ticks -= 1
-        self.ProcessTick(caller_pc, sp, state, stack)
+        self.ProcessTick(caller_pc, sp, func, state, stack)
       else:
         self.unaccounted_number_of_ticks += 1
     else:
-      entry.Tick(pc, self.ProcessStack(stack))
+      processed_stack = self.ProcessStack(stack)
+      if not entry.IsSharedLibraryEntry() and not entry.IsJSFunction():
+        func_entry_node = self.js_entries.Find(func)
+        if func_entry_node and func_entry_node.value.IsJSFunction():
+          processed_stack.insert(0, func_entry_node.value.ToString())
+      entry.Tick(pc, processed_stack)
       if self.call_graph_json:
         self.AddToPackedStacks(pc, stack)