Commit c6279388 authored by fmeawad's avatar fmeawad Committed by Commit bot

Split the TRACE_EVENTs from the LOG/HistogramTimers/TimerEvents functionality.

This CL adds a TRACE_EVENT where there is an isolated LOG, a HistogramTimer
or a TimerEvent.

Once we have a d8 tracing controller, all TimerEvents will be removed since
they do not provide an added value over TRACE_EVENTs. HistogramTimers will
remain, but their functionality will be limited to Histograms only.

BUG=v8:4562
LOG=N

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

Cr-Commit-Position: refs/heads/master@{#34099}
parent 692d3ae4
......@@ -58,6 +58,7 @@
#include "src/snapshot/natives.h"
#include "src/snapshot/snapshot.h"
#include "src/startup-data-util.h"
#include "src/tracing/trace-event.h"
#include "src/unicode-inl.h"
#include "src/v8.h"
#include "src/v8threads.h"
......@@ -1709,6 +1710,7 @@ MaybeLocal<Value> Script::Run(Local<Context> context) {
PREPARE_FOR_EXECUTION_WITH_CALLBACK(context, "v8::Script::Run()", Value)
i::AggregatingHistogramTimerScope timer(isolate->counters()->compile_lazy());
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
TRACE_EVENT0("v8", "V8.Execute");
auto fun = i::Handle<i::JSFunction>::cast(Utils::OpenHandle(this));
i::Handle<i::Object> receiver(isolate->global_proxy(), isolate);
Local<Value> result;
......@@ -1762,6 +1764,7 @@ MaybeLocal<UnboundScript> ScriptCompiler::CompileUnboundInternal(
i::Handle<i::SharedFunctionInfo> result;
{
i::HistogramTimerScope total(isolate->counters()->compile_script(), true);
TRACE_EVENT0("v8", "V8.CompileScript");
i::Handle<i::Object> name_obj;
i::Handle<i::Object> source_map_url;
int line_offset = 0;
......@@ -4281,6 +4284,7 @@ MaybeLocal<Value> Object::CallAsFunction(Local<Context> context,
PREPARE_FOR_EXECUTION_WITH_CALLBACK(context, "v8::Object::CallAsFunction()",
Value);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
TRACE_EVENT0("v8", "V8.Execute");
auto self = Utils::OpenHandle(this);
auto recv_obj = Utils::OpenHandle(*recv);
STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Object**));
......@@ -4307,6 +4311,7 @@ MaybeLocal<Value> Object::CallAsConstructor(Local<Context> context, int argc,
PREPARE_FOR_EXECUTION_WITH_CALLBACK(context,
"v8::Object::CallAsConstructor()", Value);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
TRACE_EVENT0("v8", "V8.Execute");
auto self = Utils::OpenHandle(this);
STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Object**));
i::Handle<i::Object>* args = reinterpret_cast<i::Handle<i::Object>*>(argv);
......@@ -4356,6 +4361,7 @@ MaybeLocal<Object> Function::NewInstance(Local<Context> context, int argc,
PREPARE_FOR_EXECUTION_WITH_CALLBACK(context, "v8::Function::NewInstance()",
Object);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
TRACE_EVENT0("v8", "V8.Execute");
auto self = Utils::OpenHandle(this);
STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Object**));
i::Handle<i::Object>* args = reinterpret_cast<i::Handle<i::Object>*>(argv);
......@@ -4379,6 +4385,7 @@ MaybeLocal<v8::Value> Function::Call(Local<Context> context,
v8::Local<v8::Value> argv[]) {
PREPARE_FOR_EXECUTION_WITH_CALLBACK(context, "v8::Function::Call()", Value);
i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
TRACE_EVENT0("v8", "V8.Execute");
auto self = Utils::OpenHandle(this);
i::Handle<i::Object> recv_obj = Utils::OpenHandle(*recv);
STATIC_ASSERT(sizeof(v8::Local<v8::Value>) == sizeof(i::Object**));
......@@ -7476,6 +7483,7 @@ void Isolate::LowMemoryNotification() {
{
i::HistogramTimerScope idle_notification_scope(
isolate->counters()->gc_low_memory_notification());
TRACE_EVENT0("v8", "V8.GCLowMemoryNotification");
isolate->heap()->CollectAllAvailableGarbage("low memory notification");
}
}
......
......@@ -928,10 +928,12 @@ static bool GetOptimizedCodeNow(CompilationInfo* info) {
Isolate* isolate = info->isolate();
CanonicalHandleScope canonical(isolate);
TimerEventScope<TimerEventOptimizeCode> optimize_code_timer(isolate);
TRACE_EVENT0("v8", "V8.OptimizeCode");
if (!Compiler::ParseAndAnalyze(info->parse_info())) return false;
TimerEventScope<TimerEventRecompileSynchronous> timer(isolate);
TRACE_EVENT0("v8", "V8.RecompileSynchronous");
OptimizedCompileJob job(info);
if (job.CreateGraph() != OptimizedCompileJob::SUCCEEDED ||
......@@ -958,6 +960,7 @@ static bool GetOptimizedCodeLater(CompilationInfo* info) {
Isolate* isolate = info->isolate();
CanonicalHandleScope canonical(isolate);
TimerEventScope<TimerEventOptimizeCode> optimize_code_timer(isolate);
TRACE_EVENT0("v8", "V8.OptimizeCode");
if (!isolate->optimizing_compile_dispatcher()->IsQueueAvailable()) {
if (FLAG_trace_concurrent_recompilation) {
......@@ -976,6 +979,7 @@ static bool GetOptimizedCodeLater(CompilationInfo* info) {
info->parse_info()->ReopenHandlesInNewHandleScope();
TimerEventScope<TimerEventRecompileSynchronous> timer(info->isolate());
TRACE_EVENT0("v8", "V8.RecompileSynchronous");
OptimizedCompileJob* job = new (info->zone()) OptimizedCompileJob(info);
OptimizedCompileJob::Status status = job->CreateGraph();
......@@ -1016,6 +1020,7 @@ MaybeHandle<Code> Compiler::GetLazyCode(Handle<JSFunction> function) {
DCHECK(!isolate->has_pending_exception());
DCHECK(!function->is_compiled());
TimerEventScope<TimerEventCompileCode> compile_timer(isolate);
TRACE_EVENT0("v8", "V8.CompileCode");
AggregatedHistogramTimerScope timer(isolate->counters()->compile_lazy());
// If the debugger is active, do not compile with turbofan unless we can
// deopt from turbofan code.
......@@ -1224,6 +1229,7 @@ void Compiler::CompileForLiveEdit(Handle<Script> script) {
static Handle<SharedFunctionInfo> CompileToplevel(CompilationInfo* info) {
Isolate* isolate = info->isolate();
TimerEventScope<TimerEventCompileCode> timer(isolate);
TRACE_EVENT0("v8", "V8.CompileCode");
PostponeInterruptsScope postpone(isolate);
DCHECK(!isolate->native_context().is_null());
ParseInfo* parse_info = info->parse_info();
......@@ -1283,6 +1289,7 @@ static Handle<SharedFunctionInfo> CompileToplevel(CompilationInfo* info) {
? info->isolate()->counters()->compile_eval()
: info->isolate()->counters()->compile();
HistogramTimerScope timer(rate);
TRACE_EVENT0("v8", info->is_eval() ? "V8.CompileEval" : "V8.Compile");
// Compile the code.
if (!CompileBaselineCode(info)) {
......@@ -1453,6 +1460,7 @@ Handle<SharedFunctionInfo> Compiler::CompileScript(
!isolate->debug()->is_loaded()) {
// Then check cached code provided by embedder.
HistogramTimerScope timer(isolate->counters()->compile_deserialize());
TRACE_EVENT0("v8", "V8.CompileDeserialize");
Handle<SharedFunctionInfo> result;
if (CodeSerializer::Deserialize(isolate, *cached_data, source)
.ToHandle(&result)) {
......@@ -1521,6 +1529,7 @@ Handle<SharedFunctionInfo> Compiler::CompileScript(
compile_options == ScriptCompiler::kProduceCodeCache) {
HistogramTimerScope histogram_timer(
isolate->counters()->compile_serialize());
TRACE_EVENT0("v8", "V8.CompileSerialize");
*cached_data = CodeSerializer::Serialize(isolate, result, source);
if (FLAG_profile_deserialization) {
PrintF("[Compiling and serializing took %0.3f ms]\n",
......@@ -1622,6 +1631,7 @@ Handle<SharedFunctionInfo> Compiler::GetSharedFunctionInfo(
// Generate code
TimerEventScope<TimerEventCompileCode> timer(isolate);
TRACE_EVENT0("v8", "V8.CompileCode");
Handle<ScopeInfo> scope_info;
if (lazy) {
Handle<Code> code = isolate->builtins()->CompileLazy();
......@@ -1801,6 +1811,7 @@ MaybeHandle<Code> Compiler::GetConcurrentlyOptimizedCode(
VMState<COMPILER> state(isolate);
TimerEventScope<TimerEventRecompileSynchronous> timer(info->isolate());
TRACE_EVENT0("v8", "V8.RecompileSynchronous");
Handle<SharedFunctionInfo> shared = info->shared_info();
shared->code()->set_profiler_ticks(0);
......
......@@ -198,6 +198,8 @@ class Histogram {
lookup_done_ = false;
}
const char* name() { return name_; }
protected:
// Returns the handle to the histogram.
void* GetHistogram() {
......@@ -208,7 +210,6 @@ class Histogram {
return histogram_;
}
const char* name() { return name_; }
Isolate* isolate() const { return isolate_; }
private:
......
......@@ -14,6 +14,7 @@
#include "src/interpreter/interpreter.h"
#include "src/macro-assembler.h"
#include "src/profiler/cpu-profiler.h"
#include "src/tracing/trace-event.h"
#include "src/v8.h"
......@@ -372,6 +373,7 @@ void Deoptimizer::DeoptimizeMarkedCodeForContext(Context* context) {
void Deoptimizer::DeoptimizeAll(Isolate* isolate) {
TimerEventScope<TimerEventDeoptimizeCode> timer(isolate);
TRACE_EVENT0("v8", "V8.DeoptimizeCode");
if (FLAG_trace_deopt) {
CodeTracer::Scope scope(isolate->GetCodeTracer());
PrintF(scope.file(), "[deoptimize all code in all contexts]\n");
......@@ -390,6 +392,7 @@ void Deoptimizer::DeoptimizeAll(Isolate* isolate) {
void Deoptimizer::DeoptimizeMarkedCode(Isolate* isolate) {
TimerEventScope<TimerEventDeoptimizeCode> timer(isolate);
TRACE_EVENT0("v8", "V8.DeoptimizeCode");
if (FLAG_trace_deopt) {
CodeTracer::Scope scope(isolate->GetCodeTracer());
PrintF(scope.file(), "[deoptimize marked code in all contexts]\n");
......@@ -418,6 +421,7 @@ void Deoptimizer::MarkAllCodeForContext(Context* context) {
void Deoptimizer::DeoptimizeFunction(JSFunction* function) {
TimerEventScope<TimerEventDeoptimizeCode> timer(function->GetIsolate());
TRACE_EVENT0("v8", "V8.DeoptimizeCode");
Code* code = function->code();
if (code->kind() == Code::OPTIMIZED_FUNCTION) {
// Mark the code for deoptimization and unlink any functions that also
......
......@@ -17,6 +17,7 @@
#include "src/isolate-inl.h"
#include "src/macro-assembler.h"
#include "src/snapshot/snapshot.h"
#include "src/tracing/trace-event.h"
namespace v8 {
namespace internal {
......@@ -27,6 +28,7 @@ bool FullCodeGenerator::MakeCode(CompilationInfo* info) {
Isolate* isolate = info->isolate();
TimerEventScope<TimerEventCompileFullCode> timer(info->isolate());
TRACE_EVENT0("v8", "V8.CompileFullCode");
// Ensure that the feedback vector is large enough.
info->EnsureFeedbackVector();
......
......@@ -38,6 +38,7 @@
#include "src/snapshot/natives.h"
#include "src/snapshot/serialize.h"
#include "src/snapshot/snapshot.h"
#include "src/tracing/trace-event.h"
#include "src/type-feedback-vector.h"
#include "src/utils.h"
#include "src/v8.h"
......@@ -817,6 +818,7 @@ void Heap::FinalizeIncrementalMarking(const char* gc_reason) {
GCTracer::Scope gc_scope(tracer(), GCTracer::Scope::MC_INCREMENTAL_FINALIZE);
HistogramTimerScope incremental_marking_scope(
isolate()->counters()->gc_incremental_marking_finalize());
TRACE_EVENT0("v8", "V8.GCIncrementalMarkingFinalize");
{
GCCallbacksScope scope(this);
......@@ -858,7 +860,6 @@ HistogramTimer* Heap::GCTypeTimer(GarbageCollector collector) {
}
}
void Heap::CollectAllGarbage(int flags, const char* gc_reason,
const v8::GCCallbackFlags gc_callback_flags) {
// Since we are ignoring the return value, the exact choice of space does
......@@ -1006,7 +1007,9 @@ bool Heap::CollectGarbage(GarbageCollector collector, const char* gc_reason,
GarbageCollectionPrologue();
{
HistogramTimerScope histogram_timer_scope(GCTypeTimer(collector));
HistogramTimer* gc_type_timer = GCTypeTimer(collector);
HistogramTimerScope histogram_timer_scope(gc_type_timer);
TRACE_EVENT0("v8", gc_type_timer->name());
next_gc_likely_to_collect_more =
PerformGarbageCollection(collector, gc_callback_flags);
......@@ -4204,6 +4207,7 @@ bool Heap::PerformIdleTimeAction(GCIdleTimeAction action,
case DO_FULL_GC: {
DCHECK(contexts_disposed_ > 0);
HistogramTimerScope scope(isolate_->counters()->gc_context());
TRACE_EVENT0("v8", "V8.GCContext");
CollectAllGarbage(kNoGCFlags, "idle notification: contexts disposed");
break;
}
......@@ -4289,6 +4293,7 @@ bool Heap::IdleNotification(double deadline_in_seconds) {
static_cast<double>(base::Time::kMillisecondsPerSecond);
HistogramTimerScope idle_notification_scope(
isolate_->counters()->gc_idle_notification());
TRACE_EVENT0("v8", "V8.GCIdleNotification");
double start_ms = MonotonicallyIncreasingTimeInMs();
double idle_time_in_ms = deadline_in_ms - start_ms;
......
......@@ -12,6 +12,7 @@
#include "src/heap/mark-compact-inl.h"
#include "src/heap/objects-visiting.h"
#include "src/heap/objects-visiting-inl.h"
#include "src/tracing/trace-event.h"
#include "src/v8.h"
namespace v8 {
......@@ -534,6 +535,7 @@ void IncrementalMarking::Start(const char* reason) {
HistogramTimerScope incremental_marking_scope(
heap_->isolate()->counters()->gc_incremental_marking_start());
TRACE_EVENT0("v8", "V8.GCIncrementalMarkingStart");
ResetStepCounters();
was_activated_ = true;
......@@ -1151,6 +1153,7 @@ intptr_t IncrementalMarking::Step(intptr_t allocated_bytes,
{
HistogramTimerScope incremental_marking_scope(
heap_->isolate()->counters()->gc_incremental_marking());
TRACE_EVENT0("v8", "V8.GCIncrementalMarking");
double start = heap_->MonotonicallyIncreasingTimeInMs();
// The marking speed is driven either by the allocation rate or by the rate
......
......@@ -23,6 +23,7 @@
#include "src/prototype.h"
#include "src/runtime/runtime.h"
#include "src/runtime/runtime-utils.h"
#include "src/tracing/trace-event.h"
namespace v8 {
namespace internal {
......@@ -2209,6 +2210,7 @@ void CallIC::HandleMiss(Handle<Object> function) {
// Used from ic-<arch>.cc.
RUNTIME_FUNCTION(Runtime_CallIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
DCHECK(args.length() == 3);
Handle<Object> function = args.at<Object>(0);
......@@ -2225,6 +2227,7 @@ RUNTIME_FUNCTION(Runtime_CallIC_Miss) {
// Used from ic-<arch>.cc.
RUNTIME_FUNCTION(Runtime_LoadIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> receiver = args.at<Object>(0);
Handle<Name> key = args.at<Name>(1);
......@@ -2257,6 +2260,7 @@ RUNTIME_FUNCTION(Runtime_LoadIC_Miss) {
// Used from ic-<arch>.cc
RUNTIME_FUNCTION(Runtime_KeyedLoadIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> receiver = args.at<Object>(0);
Handle<Object> key = args.at<Object>(1);
......@@ -2276,6 +2280,7 @@ RUNTIME_FUNCTION(Runtime_KeyedLoadIC_Miss) {
RUNTIME_FUNCTION(Runtime_KeyedLoadIC_MissFromStubFailure) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> receiver = args.at<Object>(0);
Handle<Object> key = args.at<Object>(1);
......@@ -2297,6 +2302,7 @@ RUNTIME_FUNCTION(Runtime_KeyedLoadIC_MissFromStubFailure) {
// Used from ic-<arch>.cc.
RUNTIME_FUNCTION(Runtime_StoreIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> receiver = args.at<Object>(0);
Handle<Name> key = args.at<Name>(1);
......@@ -2328,6 +2334,7 @@ RUNTIME_FUNCTION(Runtime_StoreIC_Miss) {
RUNTIME_FUNCTION(Runtime_StoreIC_MissFromStubFailure) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> receiver = args.at<Object>(0);
Handle<Name> key = args.at<Name>(1);
......@@ -2380,6 +2387,7 @@ RUNTIME_FUNCTION(Runtime_StoreIC_MissFromStubFailure) {
// Used from ic-<arch>.cc.
RUNTIME_FUNCTION(Runtime_KeyedStoreIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> receiver = args.at<Object>(0);
Handle<Object> key = args.at<Object>(1);
......@@ -2401,6 +2409,7 @@ RUNTIME_FUNCTION(Runtime_KeyedStoreIC_Miss) {
RUNTIME_FUNCTION(Runtime_KeyedStoreIC_MissFromStubFailure) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> receiver = args.at<Object>(0);
Handle<Object> key = args.at<Object>(1);
......@@ -2458,6 +2467,7 @@ RUNTIME_FUNCTION(Runtime_KeyedStoreIC_Slow) {
RUNTIME_FUNCTION(Runtime_ElementsTransitionAndStoreIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
// Length == 5 or 6, depending on whether the vector slot
// is passed in a virtual register or not.
......@@ -2605,6 +2615,7 @@ MaybeHandle<Object> BinaryOpIC::Transition(
RUNTIME_FUNCTION(Runtime_BinaryOpIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
DCHECK_EQ(2, args.length());
Handle<Object> left = args.at<Object>(BinaryOpICStub::kLeft);
......@@ -2620,6 +2631,7 @@ RUNTIME_FUNCTION(Runtime_BinaryOpIC_Miss) {
RUNTIME_FUNCTION(Runtime_BinaryOpIC_MissWithAllocationSite) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
DCHECK_EQ(3, args.length());
Handle<AllocationSite> allocation_site =
......@@ -2694,6 +2706,7 @@ Code* CompareIC::UpdateCaches(Handle<Object> x, Handle<Object> y) {
// Used from CompareICStub::GenerateMiss in code-stubs-<arch>.cc.
RUNTIME_FUNCTION(Runtime_CompareIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
DCHECK(args.length() == 3);
CompareIC ic(isolate, static_cast<Token::Value>(args.smi_at(2)));
......@@ -2744,6 +2757,7 @@ Handle<Object> CompareNilIC::CompareNil(Handle<Object> object) {
RUNTIME_FUNCTION(Runtime_CompareNilIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> object = args.at<Object>(0);
CompareNilIC ic(isolate);
......@@ -2769,6 +2783,7 @@ Handle<Object> ToBooleanIC::ToBoolean(Handle<Object> object) {
RUNTIME_FUNCTION(Runtime_ToBooleanIC_Miss) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
DCHECK(args.length() == 1);
HandleScope scope(isolate);
Handle<Object> object = args.at<Object>(0);
......@@ -2917,6 +2932,7 @@ RUNTIME_FUNCTION(Runtime_LoadElementWithInterceptor) {
RUNTIME_FUNCTION(Runtime_LoadIC_MissFromStubFailure) {
TimerEventScope<TimerEventIcMiss> timer(isolate);
TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.IcMiss");
HandleScope scope(isolate);
Handle<Object> receiver = args.at<Object>(0);
Handle<Name> key = args.at<Name>(1);
......
......@@ -38,19 +38,6 @@ void Logger::CallEventLogger(Isolate* isolate, const char* name, StartEnd se,
isolate->event_logger()(name, se);
}
}
if (expose_to_api) {
if (se == START) {
TRACE_EVENT_BEGIN0("v8", name);
} else {
TRACE_EVENT_END0("v8", name);
}
} else {
if (se == START) {
TRACE_EVENT_BEGIN0(TRACE_DISABLED_BY_DEFAULT("v8"), name);
} else {
TRACE_EVENT_END0(TRACE_DISABLED_BY_DEFAULT("v8"), name);
}
}
}
} // namespace internal
} // namespace v8
......
......@@ -934,6 +934,7 @@ void Logger::TimerEvent(Logger::StartEnd se, const char* name) {
void Logger::EnterExternal(Isolate* isolate) {
LOG(isolate, TimerEvent(START, TimerEventExternal::name()));
TRACE_EVENT_BEGIN0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.External");
DCHECK(isolate->current_vm_state() == JS);
isolate->set_current_vm_state(EXTERNAL);
}
......@@ -941,6 +942,7 @@ void Logger::EnterExternal(Isolate* isolate) {
void Logger::LeaveExternal(Isolate* isolate) {
LOG(isolate, TimerEvent(END, TimerEventExternal::name()));
TRACE_EVENT_END0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.External");
DCHECK(isolate->current_vm_state() == EXTERNAL);
isolate->set_current_vm_state(JS);
}
......
......@@ -7,6 +7,7 @@
#include "src/base/atomicops.h"
#include "src/full-codegen/full-codegen.h"
#include "src/isolate.h"
#include "src/tracing/trace-event.h"
#include "src/v8.h"
namespace v8 {
......@@ -59,6 +60,7 @@ class OptimizingCompileDispatcher::CompileTask : public v8::Task {
isolate_->optimizing_compile_dispatcher();
{
TimerEventScope<TimerEventRecompileConcurrent> timer(isolate_);
TRACE_EVENT0("v8", "V8.RecompileConcurrent");
if (dispatcher->recompilation_delay_ != 0) {
base::OS::Sleep(base::TimeDelta::FromMilliseconds(
......
......@@ -23,6 +23,7 @@
#include "src/parsing/scanner-character-streams.h"
#include "src/runtime/runtime.h"
#include "src/string-stream.h"
#include "src/tracing/trace-event.h"
namespace v8 {
namespace internal {
......@@ -796,6 +797,7 @@ FunctionLiteral* Parser::ParseProgram(Isolate* isolate, ParseInfo* info) {
DCHECK(parsing_on_main_thread_);
HistogramTimerScope timer_scope(isolate->counters()->parse(), true);
TRACE_EVENT0("v8", "V8.Parse");
Handle<String> source(String::cast(info->script()->source()));
isolate->counters()->total_parse_size()->Increment(source->length());
base::ElapsedTimer timer;
......@@ -964,6 +966,7 @@ FunctionLiteral* Parser::ParseLazy(Isolate* isolate, ParseInfo* info) {
// called in the main thread.
DCHECK(parsing_on_main_thread_);
HistogramTimerScope timer_scope(isolate->counters()->parse_lazy());
TRACE_EVENT0("v8", "V8.ParseLazy");
Handle<String> source(String::cast(info->script()->source()));
isolate->counters()->total_parse_size()->Increment(source->length());
base::ElapsedTimer timer;
......@@ -4838,6 +4841,8 @@ PreParser::PreParseResult Parser::ParseLazyFunctionBodyWithPreParser(
if (pre_parse_timer_ != NULL) {
pre_parse_timer_->Start();
}
TRACE_EVENT0("v8", "V8.PreParse");
DCHECK_EQ(Token::LBRACE, scanner()->current_token());
if (reusable_preparser_ == NULL) {
......
......@@ -137,6 +137,7 @@ RUNTIME_FUNCTION(Runtime_NotifyDeoptimized) {
Deoptimizer* deoptimizer = Deoptimizer::Grab(isolate);
DCHECK(AllowHeapAllocation::IsAllowed());
TimerEventScope<TimerEventDeoptimizeCode> timer(isolate);
TRACE_EVENT0("v8", "V8.DeoptimizeCode");
Handle<JSFunction> function = deoptimizer->function();
Handle<Code> optimized_code = deoptimizer->compiled_code();
......
......@@ -8,6 +8,7 @@
#include "src/vm-state.h"
#include "src/log.h"
#include "src/simulator.h"
#include "src/tracing/trace-event.h"
namespace v8 {
namespace internal {
......@@ -39,8 +40,11 @@ inline const char* StateToString(StateTag state) {
template <StateTag Tag>
VMState<Tag>::VMState(Isolate* isolate)
: isolate_(isolate), previous_tag_(isolate->current_vm_state()) {
if (FLAG_log_timer_events && previous_tag_ != EXTERNAL && Tag == EXTERNAL) {
LOG(isolate_, TimerEvent(Logger::START, TimerEventExternal::name()));
if (previous_tag_ != EXTERNAL && Tag == EXTERNAL) {
if (FLAG_log_timer_events) {
LOG(isolate_, TimerEvent(Logger::START, TimerEventExternal::name()));
}
TRACE_EVENT_BEGIN0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.External");
}
isolate_->set_current_vm_state(Tag);
}
......@@ -48,8 +52,11 @@ VMState<Tag>::VMState(Isolate* isolate)
template <StateTag Tag>
VMState<Tag>::~VMState() {
if (FLAG_log_timer_events && previous_tag_ != EXTERNAL && Tag == EXTERNAL) {
LOG(isolate_, TimerEvent(Logger::END, TimerEventExternal::name()));
if (previous_tag_ != EXTERNAL && Tag == EXTERNAL) {
if (FLAG_log_timer_events) {
LOG(isolate_, TimerEvent(Logger::END, TimerEventExternal::name()));
}
TRACE_EVENT_END0(TRACE_DISABLED_BY_DEFAULT("v8"), "V8.External");
}
isolate_->set_current_vm_state(previous_tag_);
}
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment