From 65e585fa387bd7514a6718798f09df40098a6176 Mon Sep 17 00:00:00 2001 From: "alph@chromium.org" Date: Tue, 24 Jun 2014 16:00:51 +0000 Subject: [PATCH] CPU profiler: increase the max number of captured frames. LOG=N R=jkummerow@chromium.org, loislo@chromium.org, yurys@chromium.org Review URL: https://codereview.chromium.org/357443003 git-svn-id: https://v8.googlecode.com/svn/branches/bleeding_edge@21986 ce2b1a6d-e550-0410-aec6-3dcde31c8c00 --- src/log.cc | 2 +- src/sampler.cc | 2 +- src/sampler.h | 5 +-- test/cctest/test-cpu-profiler.cc | 68 +++++++++++++++++++++++++++++++++++- test/cctest/test-log-stack-tracer.cc | 4 +-- 5 files changed, 74 insertions(+), 7 deletions(-) diff --git a/src/log.cc b/src/log.cc index c8b08ac..9603fc1 100644 --- a/src/log.cc +++ b/src/log.cc @@ -1715,7 +1715,7 @@ void Logger::TickEvent(TickSample* sample, bool overflow) { if (overflow) { msg.Append(",overflow"); } - for (int i = 0; i < sample->frames_count; ++i) { + for (unsigned i = 0; i < sample->frames_count; ++i) { msg.Append(','); msg.AppendAddress(sample->stack[i]); } diff --git a/src/sampler.cc b/src/sampler.cc index aedf75f..82fe27d 100644 --- a/src/sampler.cc +++ b/src/sampler.cc @@ -596,7 +596,7 @@ DISABLE_ASAN void TickSample::Init(Isolate* isolate, SafeStackFrameIterator it(isolate, regs.fp, regs.sp, js_entry_sp); top_frame_type = it.top_frame_type(); - int i = 0; + unsigned i = 0; while (!it.done() && i < TickSample::kMaxFramesCount) { stack[i++] = it.frame()->pc(); it.Advance(); diff --git a/src/sampler.h b/src/sampler.h index fe94a02..80fe5a9 100644 --- a/src/sampler.h +++ b/src/sampler.h @@ -44,10 +44,11 @@ struct TickSample { Address tos; // Top stack value (*sp). Address external_callback; }; - static const int kMaxFramesCount = 64; + static const unsigned kMaxFramesCountLog2 = 8; + static const unsigned kMaxFramesCount = (1 << kMaxFramesCountLog2) - 1; Address stack[kMaxFramesCount]; // Call stack. TimeTicks timestamp; - int frames_count : 8; // Number of captured frames. + unsigned frames_count : kMaxFramesCountLog2; // Number of captured frames. bool has_external_callback : 1; StackFrame::Type top_frame_type : 4; }; diff --git a/test/cctest/test-cpu-profiler.cc b/test/cctest/test-cpu-profiler.cc index 77b5bd8..6e5e23b 100644 --- a/test/cctest/test-cpu-profiler.cc +++ b/test/cctest/test-cpu-profiler.cc @@ -283,7 +283,7 @@ TEST(Issue1398) { sample->pc = code->address(); sample->tos = 0; sample->frames_count = i::TickSample::kMaxFramesCount; - for (int i = 0; i < sample->frames_count; ++i) { + for (unsigned i = 0; i < sample->frames_count; ++i) { sample->stack[i] = code->address(); } processor->FinishTickSample(); @@ -1248,6 +1248,72 @@ TEST(FunctionApplySample) { } +static const char* cpu_profiler_deep_stack_test_source = +"function foo(n) {\n" +" if (n)\n" +" foo(n - 1);\n" +" else\n" +" startProfiling('my_profile');\n" +"}\n" +"function start() {\n" +" foo(250);\n" +"}\n"; + + +// Check a deep stack +// +// [Top down]: +// 0 (root) 0 #1 +// 2 (program) 0 #2 +// 0 start 21 #3 no reason +// 0 foo 21 #4 no reason +// 0 foo 21 #5 no reason +// .... +// 0 foo 21 #253 no reason +// 1 startProfiling 0 #254 +TEST(CpuProfileDeepStack) { + v8::HandleScope scope(CcTest::isolate()); + v8::Local env = CcTest::NewContext(PROFILER_EXTENSION); + v8::Context::Scope context_scope(env); + + v8::Script::Compile(v8::String::NewFromUtf8( + env->GetIsolate(), cpu_profiler_deep_stack_test_source))->Run(); + v8::Local function = v8::Local::Cast( + env->Global()->Get(v8::String::NewFromUtf8(env->GetIsolate(), "start"))); + + v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler(); + v8::Local profile_name = + v8::String::NewFromUtf8(env->GetIsolate(), "my_profile"); + function->Call(env->Global(), 0, NULL); + v8::CpuProfile* profile = cpu_profiler->StopProfiling(profile_name); + CHECK_NE(NULL, profile); + // Dump collected profile to have a better diagnostic in case of failure. + reinterpret_cast(profile)->Print(); + + const v8::CpuProfileNode* root = profile->GetTopDownRoot(); + { + ScopedVector > names(3); + names[0] = v8::String::NewFromUtf8( + env->GetIsolate(), ProfileGenerator::kGarbageCollectorEntryName); + names[1] = v8::String::NewFromUtf8(env->GetIsolate(), + ProfileGenerator::kProgramEntryName); + names[2] = v8::String::NewFromUtf8(env->GetIsolate(), "start"); + CheckChildrenNames(root, names); + } + + const v8::CpuProfileNode* node = + GetChild(env->GetIsolate(), root, "start"); + for (int i = 0; i < 250; ++i) { + node = GetChild(env->GetIsolate(), node, "foo"); + } + // TODO(alph): + // In theory there must be one more 'foo' and a 'startProfiling' nodes, + // but due to unstable top frame extraction these might be missing. + + profile->Delete(); +} + + static const char* js_native_js_test_source = "var is_profiling = false;\n" "function foo(iterations) {\n" diff --git a/test/cctest/test-log-stack-tracer.cc b/test/cctest/test-log-stack-tracer.cc index 3f9d0b3..334a201 100644 --- a/test/cctest/test-log-stack-tracer.cc +++ b/test/cctest/test-log-stack-tracer.cc @@ -172,7 +172,7 @@ TEST(CFromJSStackTrace) { CHECK_EQ(FUNCTION_ADDR(i::TraceExtension::Trace), sample.external_callback); // Stack tracing will start from the first JS function, i.e. "JSFuncDoTrace" - int base = 0; + unsigned base = 0; CHECK_GT(sample.frames_count, base + 1); CHECK(IsAddressWithinFuncCode( @@ -225,7 +225,7 @@ TEST(PureJSStackTrace) { CHECK_EQ(FUNCTION_ADDR(i::TraceExtension::JSTrace), sample.external_callback); // Stack sampling will start from the caller of JSFuncDoTrace, i.e. "JSTrace" - int base = 0; + unsigned base = 0; CHECK_GT(sample.frames_count, base + 1); CHECK(IsAddressWithinFuncCode(context, "JSTrace", sample.stack[base + 0])); CHECK(IsAddressWithinFuncCode( -- 2.7.4