Correctly report stack trace when current function is FunctionApply builtin
authoryurys@chromium.org <yurys@chromium.org@ce2b1a6d-e550-0410-aec6-3dcde31c8c00>
Wed, 3 Jul 2013 14:04:37 +0000 (14:04 +0000)
committeryurys@chromium.org <yurys@chromium.org@ce2b1a6d-e550-0410-aec6-3dcde31c8c00>
Wed, 3 Jul 2013 14:04:37 +0000 (14:04 +0000)
When pc is inside FunctionApply builtin function the top frame may be either
2) Internal stack frame created by FunctionApply itself.
In this case we know its caller's pc and can correctly resolve calling function.
1) Frame of the calling JavaScript function that invoked .apply(). In this case we have no practical reliable way to find out the caller's pc so we mark the caller's frame as 'unresolved'.

All this logic is implemented in ProfileGenerator. SafeStackFrameIterator is extended to provide type of the current top stack frame (iteration actually starts from the caller's frame as we know top function from pc).

BUG=252097
R=jkummerow@chromium.org, loislo@chromium.org

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

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

src/frames.cc
src/frames.h
src/profile-generator.cc
src/sampler.cc
src/sampler.h
test/cctest/test-cpu-profiler.cc

index e883c9831d63a5ed51f5b5e2daf061a122846fef..4afd4d49d15c4d60e3026ad9b5beea20da12ce12 100644 (file)
@@ -218,19 +218,37 @@ SafeStackFrameIterator::SafeStackFrameIterator(
     Isolate* isolate,
     Address fp, Address sp, Address low_bound, Address high_bound) :
     StackFrameIteratorBase(isolate, false),
-    low_bound_(low_bound), high_bound_(high_bound) {
+    low_bound_(low_bound), high_bound_(high_bound),
+    top_frame_type_(StackFrame::NONE) {
   StackFrame::State state;
   StackFrame::Type type;
   ThreadLocalTop* top = isolate->thread_local_top();
   if (IsValidTop(top)) {
     type = ExitFrame::GetStateForFramePointer(Isolate::c_entry_fp(top), &state);
+    top_frame_type_ = type;
   } else if (IsValidStackAddress(fp)) {
     ASSERT(fp != NULL);
     state.fp = fp;
     state.sp = sp;
     state.pc_address = StackFrame::ResolveReturnAddressLocation(
         reinterpret_cast<Address*>(StandardFrame::ComputePCAddress(fp)));
-    type = StackFrame::ComputeType(this, &state);
+    // StackFrame::ComputeType will read both kContextOffset and kMarkerOffset,
+    // we check only that kMarkerOffset is within the stack bounds and do
+    // compile time check that kContextOffset slot is pushed on the stack before
+    // kMarkerOffset.
+    STATIC_ASSERT(StandardFrameConstants::kMarkerOffset <
+                  StandardFrameConstants::kContextOffset);
+    Address frame_marker = fp + StandardFrameConstants::kMarkerOffset;
+    if (IsValidStackAddress(frame_marker)) {
+      type = StackFrame::ComputeType(this, &state);
+      top_frame_type_ = type;
+    } else {
+      // Mark the frame as JAVA_SCRIPT if we cannot determine its type.
+      // The frame anyways will be skipped.
+      type = StackFrame::JAVA_SCRIPT;
+      // Top frame is incomplete so we cannot reliably determine its type.
+      top_frame_type_ = StackFrame::NONE;
+    }
   } else {
     return;
   }
index 9ca218ac52d848405662dbbfad4816f5d12b2b18..ccbb2d1bb82046287a6b71642c555ef857b151ff 100644 (file)
@@ -886,6 +886,8 @@ class SafeStackFrameIterator: public StackFrameIteratorBase {
   inline JavaScriptFrame* frame() const;
   void Advance();
 
+  StackFrame::Type top_frame_type() const { return top_frame_type_; }
+
  private:
   void AdvanceOneFrame();
 
@@ -899,6 +901,7 @@ class SafeStackFrameIterator: public StackFrameIteratorBase {
 
   const Address low_bound_;
   const Address high_bound_;
+  StackFrame::Type top_frame_type_;
 };
 
 
index aeb80a3bc625f6b42db8e35797163572c855a274..10bd94e7a374cf889312728b7b39c1101ebba9a4 100644 (file)
@@ -906,11 +906,16 @@ void ProfileGenerator::RecordTickSample(const TickSample& sample) {
         }
         *entry++ = pc_entry;
 
-        if (pc_entry->builtin_id() == Builtins::kFunctionCall) {
-          // When current function is FunctionCall builtin tos is sometimes
-          // address of the function that invoked it but sometimes it's one
-          // of the arguments. We simply replace the frame with 'unknown' entry.
-          *entry++ = unresolved_entry_;
+        if (pc_entry->builtin_id() == Builtins::kFunctionCall ||
+            pc_entry->builtin_id() == Builtins::kFunctionApply) {
+          // When current function is FunctionCall or FunctionApply builtin the
+          // top frame is either frame of the calling JS function or internal
+          // frame. In the latter case we know the caller for sure but in the
+          // former case we don't so we simply replace the frame with
+          // 'unresolved' entry.
+          if (sample.top_frame_type == StackFrame::JAVA_SCRIPT) {
+            *entry++ = unresolved_entry_;
+          }
         }
       }
     }
index 6d97110b1d5deecd08e518deb20d3d1870d4ae36..63d0aa88cc722468602f1da7ac023071a268c76c 100644 (file)
@@ -637,6 +637,7 @@ DISABLE_ASAN void TickSample::Trace(Isolate* isolate) {
   }
 
   SafeStackFrameIterator it(isolate, fp, sp, sp, js_entry_sp);
+  top_frame_type = it.top_frame_type();
   int i = 0;
   while (!it.done() && i < TickSample::kMaxFramesCount) {
     stack[i++] = it.frame()->pc();
index 1d9ac8723bf0487ab6cd37ac4dc2af7b4d3c41c7..3875a29e663e1bb8c797553515e820f56eb7ff14 100644 (file)
@@ -52,7 +52,8 @@ struct TickSample {
         fp(NULL),
         external_callback(NULL),
         frames_count(0),
-        has_external_callback(false) {}
+        has_external_callback(false),
+        top_frame_type(StackFrame::NONE) {}
   void Trace(Isolate* isolate);
   StateTag state;  // The state of the VM.
   Address pc;      // Instruction pointer.
@@ -66,6 +67,7 @@ struct TickSample {
   Address stack[kMaxFramesCount];  // Call stack.
   int frames_count : 8;  // Number of captured frames.
   bool has_external_callback : 1;
+  StackFrame::Type top_frame_type : 4;
 };
 
 class Sampler {
index 223f5fc3925057dc70e228c8a39520c45972260b..97636a35ff0ea313507176717b5951be060e4162 100644 (file)
@@ -1089,8 +1089,9 @@ TEST(FunctionCallSample) {
 
   const v8::CpuProfileNode* startNode = GetChild(root, "start");
   {
-    ScopedVector<v8::Handle<v8::String> > names(1);
+    ScopedVector<v8::Handle<v8::String> > names(2);
     names[0] = v8::String::New("bar");
+    names[1] = v8::String::New("call");
     CheckChildrenNames(startNode, names);
   }
 
@@ -1105,3 +1106,101 @@ TEST(FunctionCallSample) {
   cpu_profiler->DeleteAllCpuProfiles();
 }
 
+
+static const char* function_apply_test_source = "function bar(iterations) {\n"
+"}\n"
+"function test() {\n"
+"  bar.apply(this, [10 * 1000]);\n"
+"}\n"
+"function start(duration) {\n"
+"  var start = Date.now();\n"
+"  while (Date.now() - start < duration) {\n"
+"    try {\n"
+"      test();\n"
+"    } catch(e) {}\n"
+"  }\n"
+"}";
+
+
+// [Top down]:
+//    94     0   (root) [-1] #0 1
+//     2     2    (garbage collector) [-1] #0 7
+//    82    49    start [-1] #16 3
+//     1     0      (unresolved function) [-1] #0 8
+//     1     1        apply [-1] #0 9
+//    32    21      test [-1] #16 4
+//     2     2        bar [-1] #16 6
+//     9     9        apply [-1] #0 5
+//    10    10    (program) [-1] #0 2
+TEST(FunctionApplySample) {
+  LocalContext env;
+  v8::HandleScope scope(env->GetIsolate());
+
+  v8::Script::Compile(v8::String::New(function_apply_test_source))->Run();
+  v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast(
+      env->Global()->Get(v8::String::New("start")));
+
+  v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler();
+  v8::Local<v8::String> profile_name = v8::String::New("my_profile");
+
+  cpu_profiler->StartCpuProfiling(profile_name);
+  int32_t duration_ms = 100;
+#if defined(_WIN32) || defined(_WIN64)
+  // 100ms is not enough on Windows. See
+  // https://code.google.com/p/v8/issues/detail?id=2628
+  duration_ms = 400;
+#endif
+  v8::Handle<v8::Value> args[] = { v8::Integer::New(duration_ms) };
+  function->Call(env->Global(), ARRAY_SIZE(args), args);
+  const v8::CpuProfile* profile = cpu_profiler->StopCpuProfiling(profile_name);
+
+  CHECK_NE(NULL, profile);
+  // Dump collected profile to have a better diagnostic in case of failure.
+  reinterpret_cast<i::CpuProfile*>(
+      const_cast<v8::CpuProfile*>(profile))->Print();
+
+  const v8::CpuProfileNode* root = profile->GetTopDownRoot();
+  {
+    ScopedVector<v8::Handle<v8::String> > names(3);
+    names[0] = v8::String::New(ProfileGenerator::kGarbageCollectorEntryName);
+    names[1] = v8::String::New(ProfileGenerator::kProgramEntryName);
+    names[2] = v8::String::New("start");
+    // Don't allow |test|, |bar| and |apply| nodes to be at the top level.
+    CheckChildrenNames(root, names);
+  }
+
+  // In case of GC stress tests all samples may be in GC phase and there
+  // won't be |start| node in the profile.
+  bool is_gc_stress_testing =
+      (i::FLAG_gc_interval != -1) || i::FLAG_stress_compaction;
+
+  const v8::CpuProfileNode* startNode = FindChild(root, "start");
+  CHECK(is_gc_stress_testing || startNode);
+  if (startNode) {
+    {
+      ScopedVector<v8::Handle<v8::String> > names(2);
+      names[0] = v8::String::New("test");
+      names[1] = v8::String::New(ProfileGenerator::kUnresolvedFunctionName);
+      CheckChildrenNames(startNode, names);
+    }
+
+    const v8::CpuProfileNode* testNode = FindChild(startNode, "test");
+    CHECK(is_gc_stress_testing || testNode);
+    if (testNode) {
+      ScopedVector<v8::Handle<v8::String> > names(2);
+      names[0] = v8::String::New("bar");
+      names[1] = v8::String::New("apply");
+      CheckChildrenNames(testNode, names);
+    }
+
+    if (const v8::CpuProfileNode* unresolvedNode =
+            FindChild(startNode, ProfileGenerator::kUnresolvedFunctionName)) {
+      ScopedVector<v8::Handle<v8::String> > names(1);
+      names[0] = v8::String::New("apply");
+      CheckChildrenNames(unresolvedNode, names);
+      GetChild(unresolvedNode, "apply");
+    }
+  }
+
+  cpu_profiler->DeleteAllCpuProfiles();
+}