From 56788625b62244445ab5e99dcef6b8ccb64520fc Mon Sep 17 00:00:00 2001 From: "mikhail.naganov@gmail.com" Date: Tue, 22 Feb 2011 16:31:24 +0000 Subject: [PATCH] Fix CPU profiling for Crankshaft. The main issue was due to multiple recompilations of functions. Now code objects are grouped by function using SFI object address. JSFunction objects are no longer tracked, instead we track SFI object moves. To pick a correct code version, we now sample return addresses instead of JSFunction addresses. tools/{linux|mac|windows}-tickprocessor scripts differentiate between code optimization states for the same function (using * and ~ prefixes introduced earlier). DevTools CPU profiler treats all variants of function code as a single function. ll_prof treats each optimized variant as a separate entry, because it can disassemble each one of them. tickprocessor.py not updated -- it is deprecated and will be removed. BUG=v8/1087,b/3178160 TEST=all existing tests pass, including Chromium layout tests Review URL: http://codereview.chromium.org/6551011 git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@6902 ce2b1a6d-e550-0410-aec6-3dcde31c8c00 --- src/compiler.cc | 61 ++++----- src/compiler.h | 5 +- src/cpu-profiler-inl.h | 7 +- src/cpu-profiler.cc | 140 ++++++------------- src/cpu-profiler.h | 48 +++---- src/handles.cc | 7 +- src/heap.cc | 6 +- src/hydrogen.cc | 5 +- src/log-utils.cc | 2 + src/log.cc | 151 +++++++++------------ src/log.h | 26 ++-- src/mark-compact.cc | 12 +- src/platform.h | 10 +- src/profile-generator-inl.h | 11 +- src/profile-generator.cc | 78 +++++------ src/profile-generator.h | 12 +- test/cctest/test-cpu-profiler.cc | 10 +- test/cctest/test-log-stack-tracer.cc | 32 ++--- test/cctest/test-log.cc | 23 +--- test/cctest/test-profile-generator.cc | 6 +- .../mjsunit/tools/tickprocessor-test-func-info.log | 10 +- tools/ll_prof.py | 12 +- tools/profile.js | 141 +++++++++++++------ tools/tickprocessor.js | 75 +++++----- 24 files changed, 408 insertions(+), 482 deletions(-) diff --git a/src/compiler.cc b/src/compiler.cc index 5b49cdf..f392cce 100755 --- a/src/compiler.cc +++ b/src/compiler.cc @@ -261,10 +261,8 @@ static bool MakeCrankshaftCode(CompilationInfo* info) { Handle shared = info->shared_info(); shared->EnableDeoptimizationSupport(*unoptimized.code()); // The existing unoptimized code was replaced with the new one. - Compiler::RecordFunctionCompilation(Logger::LAZY_COMPILE_TAG, - Handle(shared->DebugName()), - shared->start_position(), - &unoptimized); + Compiler::RecordFunctionCompilation( + Logger::LAZY_COMPILE_TAG, &unoptimized, shared); } } @@ -414,13 +412,25 @@ static Handle MakeFunctionInfo(CompilationInfo* info) { return Handle::null(); } + // Allocate function. ASSERT(!info->code().is_null()); + Handle result = + Factory::NewSharedFunctionInfo( + lit->name(), + lit->materialized_literal_count(), + info->code(), + SerializedScopeInfo::Create(info->scope())); + + ASSERT_EQ(RelocInfo::kNoPosition, lit->function_token_position()); + Compiler::SetFunctionInfo(result, lit, true, script); + if (script->name()->IsString()) { PROFILE(CodeCreateEvent( info->is_eval() ? Logger::EVAL_TAG : Logger::ToNativeByScript(Logger::SCRIPT_TAG, *script), *info->code(), + *result, String::cast(script->name()))); GDBJIT(AddCode(Handle(String::cast(script->name())), script, @@ -431,21 +441,11 @@ static Handle MakeFunctionInfo(CompilationInfo* info) { ? Logger::EVAL_TAG : Logger::ToNativeByScript(Logger::SCRIPT_TAG, *script), *info->code(), - "")); + *result, + Heap::empty_string())); GDBJIT(AddCode(Handle(), script, info->code())); } - // Allocate function. - Handle result = - Factory::NewSharedFunctionInfo( - lit->name(), - lit->materialized_literal_count(), - info->code(), - SerializedScopeInfo::Create(info->scope())); - - ASSERT_EQ(RelocInfo::kNoPosition, lit->function_token_position()); - Compiler::SetFunctionInfo(result, lit, true, script); - // Hint to the runtime system used when allocating space for initial // property space by setting the expected number of properties for // the instances of the function. @@ -612,10 +612,7 @@ bool Compiler::CompileLazy(CompilationInfo* info) { ASSERT(!info->code().is_null()); Handle code = info->code(); Handle function = info->closure(); - RecordFunctionCompilation(Logger::LAZY_COMPILE_TAG, - Handle(shared->DebugName()), - shared->start_position(), - info); + RecordFunctionCompilation(Logger::LAZY_COMPILE_TAG, info, shared); if (info->IsOptimizing()) { function->ReplaceCode(*code); @@ -723,10 +720,6 @@ Handle Compiler::BuildFunctionInfo(FunctionLiteral* literal, ASSERT(!info.code().is_null()); // Function compilation complete. - RecordFunctionCompilation(Logger::FUNCTION_TAG, - literal->debug_name(), - literal->start_position(), - &info); scope_info = SerializedScopeInfo::Create(info.scope()); } @@ -737,6 +730,7 @@ Handle Compiler::BuildFunctionInfo(FunctionLiteral* literal, info.code(), scope_info); SetFunctionInfo(result, literal, false, script); + RecordFunctionCompilation(Logger::FUNCTION_TAG, &info, result); result->set_allows_lazy_compilation(allow_lazy); // Set the expected number of properties for instances and return @@ -775,28 +769,31 @@ void Compiler::SetFunctionInfo(Handle function_info, void Compiler::RecordFunctionCompilation(Logger::LogEventsAndTags tag, - Handle name, - int start_position, - CompilationInfo* info) { + CompilationInfo* info, + Handle shared) { + // SharedFunctionInfo is passed separately, because if CompilationInfo + // was created using Script object, it will not have it. + // Log the code generation. If source information is available include // script name and line number. Check explicitly whether logging is // enabled as finding the line number is not free. - if (Logger::is_logging() || - CpuProfiler::is_profiling()) { + if (Logger::is_logging() || CpuProfiler::is_profiling()) { Handle