From c89921258754569147258c33175e9687b1fe4bd2 Mon Sep 17 00:00:00 2001 From: rmcilroy Date: Tue, 3 Jan 2017 10:11:58 -0800 Subject: [PATCH] [Compiler] Track Ignition background compilation separately in RuntimeStats. Tracks background compilation of Ignition in a separate bucket from main thread compilation. Also add some more compilation buckets for functions which can take a significant proportion of compilation. BUG=v8:5203,v8:5215 Review-Url: https://codereview.chromium.org/2577263002 Cr-Original-Commit-Position: refs/heads/master@{#42026} Committed: https://chromium.googlesource.com/v8/v8/+/b0e9116d59326a4f9a4f4691b61a510e342338c9 Review-Url: https://codereview.chromium.org/2577263002 Cr-Commit-Position: refs/heads/master@{#42042} --- src/compiler.cc | 22 ++++++++++++-- src/compiler.h | 13 ++++---- src/counters.h | 5 ++++ src/interpreter/interpreter.cc | 55 ++++++++++++++++++++++++++++++---- tools/callstats.html | 3 ++ tools/callstats.py | 8 +++++ 6 files changed, 92 insertions(+), 14 deletions(-) diff --git a/src/compiler.cc b/src/compiler.cc index 392972cbc9..ee89ba8fe8 100644 --- a/src/compiler.cc +++ b/src/compiler.cc @@ -70,6 +70,15 @@ struct ScopedTimer { // ---------------------------------------------------------------------------- // Implementation of CompilationJob +CompilationJob::CompilationJob(Isolate* isolate, CompilationInfo* info, + const char* compiler_name, State initial_state) + : info_(info), + isolate_thread_id_(isolate->thread_id()), + compiler_name_(compiler_name), + state_(initial_state), + stack_limit_(isolate->stack_guard()->real_climit()), + executed_on_background_thread_(false) {} + CompilationJob::Status CompilationJob::PrepareJob() { DCHECK(ThreadId::Current().Equals(info()->isolate()->thread_id())); DisallowJavascriptExecution no_js(isolate()); @@ -98,8 +107,10 @@ CompilationJob::Status CompilationJob::ExecuteJob() { no_handles.reset(new DisallowHandleAllocation()); no_deref.reset(new DisallowHandleDereference()); no_dependency_change.reset(new DisallowCodeDependencyChange()); + executed_on_background_thread_ = + !ThreadId::Current().Equals(isolate_thread_id_); } else { - DCHECK(ThreadId::Current().Equals(info()->isolate()->thread_id())); + DCHECK(ThreadId::Current().Equals(isolate_thread_id_)); } // Delegate to the underlying implementation. @@ -477,6 +488,8 @@ void EnsureSharedFunctionInfosArrayOnScript(ParseInfo* info) { } MUST_USE_RESULT MaybeHandle GetUnoptimizedCode(CompilationInfo* info) { + RuntimeCallTimerScope runtimeTimer( + info->isolate(), &RuntimeCallStats::CompileGetUnoptimizedCode); VMState state(info->isolate()); PostponeInterruptsScope postpone(info->isolate()); @@ -499,6 +512,9 @@ MUST_USE_RESULT MaybeHandle GetUnoptimizedCode(CompilationInfo* info) { MUST_USE_RESULT MaybeHandle GetCodeFromOptimizedCodeMap( Handle function, BailoutId osr_ast_id) { + RuntimeCallTimerScope runtimeTimer( + function->GetIsolate(), + &RuntimeCallStats::CompileGetFromOptimizedCodeMap); Handle shared(function->shared()); DisallowHeapAllocation no_gc; CodeAndLiterals cached = shared->SearchOptimizedCodeMap( @@ -884,8 +900,6 @@ MaybeHandle GetLazyCode(Handle function) { DCHECK(!isolate->has_pending_exception()); DCHECK(!function->is_compiled()); TimerEventScope compile_timer(isolate); - RuntimeCallTimerScope runtimeTimer(isolate, - &RuntimeCallStats::CompileCodeLazy); TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8.compile"), "V8.CompileCode"); AggregatedHistogramTimerScope timer(isolate->counters()->compile_lazy()); @@ -1047,6 +1061,8 @@ Handle CompileToplevel(CompilationInfo* info) { bool Compiler::Analyze(ParseInfo* info) { DCHECK_NOT_NULL(info->literal()); + RuntimeCallTimerScope runtimeTimer(info->isolate(), + &RuntimeCallStats::CompileAnalyse); if (!Rewriter::Rewrite(info)) return false; DeclarationScope::Analyze(info, AnalyzeMode::kRegular); if (!Renumber(info)) return false; diff --git a/src/compiler.h b/src/compiler.h index e7110fe36a..4c008d2e23 100644 --- a/src/compiler.h +++ b/src/compiler.h @@ -163,11 +163,7 @@ class CompilationJob { CompilationJob(Isolate* isolate, CompilationInfo* info, const char* compiler_name, - State initial_state = State::kReadyToPrepare) - : info_(info), - compiler_name_(compiler_name), - state_(initial_state), - stack_limit_(isolate->stack_guard()->real_climit()) {} + State initial_state = State::kReadyToPrepare); virtual ~CompilationJob() {} // Prepare the compile job. Must be called on the main thread. @@ -196,6 +192,11 @@ class CompilationJob { void set_stack_limit(uintptr_t stack_limit) { stack_limit_ = stack_limit; } uintptr_t stack_limit() const { return stack_limit_; } + bool executed_on_background_thread() const { + DCHECK_IMPLIES(!can_execute_on_background_thread(), + !executed_on_background_thread_); + return executed_on_background_thread_; + } State state() const { return state_; } CompilationInfo* info() const { return info_; } Isolate* isolate() const; @@ -212,12 +213,14 @@ class CompilationJob { private: CompilationInfo* info_; + ThreadId isolate_thread_id_; base::TimeDelta time_taken_to_prepare_; base::TimeDelta time_taken_to_execute_; base::TimeDelta time_taken_to_finalize_; const char* compiler_name_; State state_; uintptr_t stack_limit_; + bool executed_on_background_thread_; MUST_USE_RESULT Status UpdateState(Status status, State next_state) { if (status == SUCCEEDED) { diff --git a/src/counters.h b/src/counters.h index 359bf93ce7..7c4735bc73 100644 --- a/src/counters.h +++ b/src/counters.h @@ -691,7 +691,12 @@ class RuntimeCallTimer final { V(CompileDeserialize) \ V(CompileEval) \ V(CompileFullCode) \ + V(CompileGetFromOptimizedCodeMap) \ + V(CompileGetUnoptimizedCode) \ + V(CompileAnalyse) \ V(CompileIgnition) \ + V(CompileBackgroundIgnition) \ + V(CompileIgnitionFinalization) \ V(CompilerDispatcher) \ V(CompileSerialize) \ V(DeoptimizeCode) \ diff --git a/src/interpreter/interpreter.cc b/src/interpreter/interpreter.cc index 724c159c5e..a0e92f345b 100644 --- a/src/interpreter/interpreter.cc +++ b/src/interpreter/interpreter.cc @@ -41,9 +41,41 @@ class InterpreterCompilationJob final : public CompilationJob { Status FinalizeJobImpl() final; private: + class TimerScope final { + public: + TimerScope(RuntimeCallStats* stats, RuntimeCallStats::CounterId counter_id) + : stats_(stats) { + if (V8_UNLIKELY(FLAG_runtime_stats)) { + RuntimeCallStats::Enter(stats_, &timer_, counter_id); + } + } + + explicit TimerScope(RuntimeCallCounter* counter) : stats_(nullptr) { + if (V8_UNLIKELY(FLAG_runtime_stats)) { + timer_.Start(counter, nullptr); + } + } + + ~TimerScope() { + if (V8_UNLIKELY(FLAG_runtime_stats)) { + if (stats_) { + RuntimeCallStats::Leave(stats_, &timer_); + } else { + timer_.Stop(); + } + } + } + + private: + RuntimeCallStats* stats_; + RuntimeCallTimer timer_; + }; + BytecodeGenerator* generator() { return &generator_; } BytecodeGenerator generator_; + RuntimeCallStats* runtime_call_stats_; + RuntimeCallCounter background_execute_counter_; DISALLOW_COPY_AND_ASSIGN(InterpreterCompilationJob); }; @@ -162,7 +194,9 @@ int Interpreter::InterruptBudget() { InterpreterCompilationJob::InterpreterCompilationJob(CompilationInfo* info, LazyCompilationMode mode) : CompilationJob(info->isolate(), info, "Ignition"), - generator_(info, mode) {} + generator_(info, mode), + runtime_call_stats_(info->isolate()->counters()->runtime_call_stats()), + background_execute_counter_("CompileBackgroundIgnition") {} InterpreterCompilationJob::Status InterpreterCompilationJob::PrepareJobImpl() { CodeGenerator::MakeCodePrologue(info(), "interpreter"); @@ -178,11 +212,11 @@ InterpreterCompilationJob::Status InterpreterCompilationJob::PrepareJobImpl() { } InterpreterCompilationJob::Status InterpreterCompilationJob::ExecuteJobImpl() { - // TODO(5203): These timers aren't thread safe, move to using the CompilerJob - // timers. - RuntimeCallTimerScope runtimeTimer(info()->isolate(), - &RuntimeCallStats::CompileIgnition); - TimerEventScope timer(info()->isolate()); + TimerScope runtimeTimer = + executed_on_background_thread() + ? TimerScope(&background_execute_counter_) + : TimerScope(runtime_call_stats_, &RuntimeCallStats::CompileIgnition); + // TODO(lpy): add support for background compilation RCS trace. TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8.compile"), "V8.CompileIgnition"); generator()->GenerateBytecode(stack_limit()); @@ -194,6 +228,15 @@ InterpreterCompilationJob::Status InterpreterCompilationJob::ExecuteJobImpl() { } InterpreterCompilationJob::Status InterpreterCompilationJob::FinalizeJobImpl() { + // Add background runtime call stats. + if (V8_UNLIKELY(FLAG_runtime_stats && executed_on_background_thread())) { + runtime_call_stats_->CompileBackgroundIgnition.Add( + &background_execute_counter_); + } + + RuntimeCallTimerScope runtimeTimer( + runtime_call_stats_, &RuntimeCallStats::CompileIgnitionFinalization); + Handle bytecodes = generator()->FinalizeBytecode(isolate()); if (generator()->HasStackOverflow()) { return FAILED; diff --git a/tools/callstats.html b/tools/callstats.html index da65418cb6..8825f48a5d 100644 --- a/tools/callstats.html +++ b/tools/callstats.html @@ -1443,6 +1443,7 @@ code is governed by a BSD-style license that can be found in the LICENSE file. this.total, Group.groups.get('ic').entry(), Group.groups.get('optimize').entry(), + Group.groups.get('compile-background').entry(), Group.groups.get('compile').entry(), Group.groups.get('parse-background').entry(), Group.groups.get('parse').entry(), @@ -1651,6 +1652,8 @@ code is governed by a BSD-style license that can be found in the LICENSE file. Group.add('ic', new Group('IC', /.*IC_.*/, "#3366CC")); Group.add('optimize', new Group('Optimize', /StackGuard|.*Optimize.*|.*Deoptimize.*|Recompile.*/, "#DC3912")); + Group.add('compile-background', new Group('Compile-Background', + /(.*CompileBackground.*)/, "#b9a720")); Group.add('compile', new Group('Compile', /(^Compile.*)|(.*_Compile.*)/, "#FFAA00")); Group.add('parse-background', diff --git a/tools/callstats.py b/tools/callstats.py index fd717a3386..9c9f792070 100755 --- a/tools/callstats.py +++ b/tools/callstats.py @@ -349,6 +349,7 @@ def read_stats(path, domain, args): ('Group-IC', re.compile(".*IC_.*")), ('Group-Optimize', re.compile("StackGuard|.*Optimize.*|.*Deoptimize.*|Recompile.*")), + ('Group-CompileBackground', re.compile("(.*CompileBackground.*)")), ('Group-Compile', re.compile("(^Compile.*)|(.*_Compile.*)")), ('Group-ParseBackground', re.compile(".*ParseBackground.*")), ('Group-Parse', re.compile(".*Parse.*")), @@ -402,6 +403,13 @@ def read_stats(path, domain, args): group_data['time'] += entries[group_name]['time'] group_data['count'] += entries[group_name]['count'] entries['Group-Parse-Total'] = group_data + # Calculate the Compile-Total group + group_data = { 'time': 0, 'count': 0 } + for group_name, regexp in groups: + if not group_name.startswith('Group-Compile'): continue + group_data['time'] += entries[group_name]['time'] + group_data['count'] += entries[group_name]['count'] + entries['Group-Compile-Total'] = group_data # Append the sums as single entries to domain. for key in entries: if key not in domain: domain[key] = { 'time_list': [], 'count_list': [] }