[vm] Misc timeline tweaks.

- Move compiler pass events to a new CompilerVerbose stream
 - Remove serialization phase events
 - Add class name to class finalization event (lost along with finalization events in recent cleanups of finalization)
 - Add event for kernel loading

Change-Id: Ie72bced978400ea174c1551c961baa55c691b019
Reviewed-on: https://dart-review.googlesource.com/c/90883
Commit-Queue: Ryan Macnak <rmacnak@google.com>
Reviewed-by: Zach Anderson <zra@google.com>
Reviewed-by: Alexander Markov <alexmarkov@google.com>
This commit is contained in:
Ryan Macnak 2019-01-25 18:37:05 +00:00 committed by commit-bot@chromium.org
parent 874f9d0bdf
commit 169331abb1
16 changed files with 76 additions and 108 deletions

View file

@ -1116,17 +1116,26 @@ void ClassFinalizer::FinalizeTypesInClass(const Class& cls) {
}
void ClassFinalizer::FinalizeClass(const Class& cls) {
Thread* thread = Thread::Current();
HANDLESCOPE(thread);
ASSERT(cls.is_type_finalized());
if (cls.is_finalized()) {
return;
}
Thread* thread = Thread::Current();
HANDLESCOPE(thread);
if (FLAG_trace_class_finalization) {
THR_Print("Finalize %s\n", cls.ToCString());
}
TIMELINE_DURATION(thread, Compiler, "ClassFinalizer::FinalizeClass");
#if defined(SUPPORT_TIMELINE)
TimelineDurationScope tds(thread, Timeline::GetCompilerStream(),
"FinalizeClass");
if (tds.enabled()) {
tds.SetNumArguments(1);
tds.CopyArgument(0, "class", cls.ToCString());
}
#endif // defined(SUPPORT_TIMELINE)
#if !defined(DART_PRECOMPILED_RUNTIME)
// If loading from a kernel, make sure that the class is fully loaded.

View file

@ -593,8 +593,6 @@ class FunctionDeserializationCluster : public DeserializationCluster {
}
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
TIMELINE_DURATION(Thread::Current(), Isolate, "Function");
if (kind == Snapshot::kFullAOT) {
Function& func = Function::Handle(zone);
for (intptr_t i = start_index_; i < stop_index_; i++) {
@ -1006,8 +1004,6 @@ class FieldDeserializationCluster : public DeserializationCluster {
}
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
TIMELINE_DURATION(Thread::Current(), Isolate, "Field");
Field& field = Field::Handle(zone);
if (!Isolate::Current()->use_field_guards()) {
for (intptr_t i = start_index_; i < stop_index_; i++) {
@ -1319,8 +1315,6 @@ class KernelProgramInfoDeserializationCluster : public DeserializationCluster {
}
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
TIMELINE_DURATION(Thread::Current(), Isolate, "KernelProgramInfo");
Array& array = Array::Handle(zone);
KernelProgramInfo& info = KernelProgramInfo::Handle(zone);
for (intptr_t id = start_index_; id < stop_index_; id++) {
@ -2332,8 +2326,6 @@ class MegamorphicCacheDeserializationCluster : public DeserializationCluster {
}
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
TIMELINE_DURATION(Thread::Current(), Isolate, "MegamorphicCache");
#if defined(DART_PRECOMPILED_RUNTIME)
if (FLAG_use_bare_instructions) {
// By default, every megamorphic call site will load the target
@ -2869,8 +2861,6 @@ class TypeDeserializationCluster : public DeserializationCluster {
}
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
TIMELINE_DURATION(Thread::Current(), Isolate, "Type");
Type& type = Type::Handle(zone);
Code& stub = Code::Handle(zone);
@ -2969,8 +2959,6 @@ class TypeRefDeserializationCluster : public DeserializationCluster {
}
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
TIMELINE_DURATION(Thread::Current(), Isolate, "TypeRef");
TypeRef& type_ref = TypeRef::Handle(zone);
Code& stub = Code::Handle(zone);
@ -3065,8 +3053,6 @@ class TypeParameterDeserializationCluster : public DeserializationCluster {
}
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
TIMELINE_DURATION(Thread::Current(), Isolate, "TypeParameter");
TypeParameter& type_param = TypeParameter::Handle(zone);
Code& stub = Code::Handle(zone);
@ -3228,8 +3214,6 @@ class MintDeserializationCluster : public DeserializationCluster {
void ReadFill(Deserializer* d) {}
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
TIMELINE_DURATION(Thread::Current(), Isolate, "Mint");
const Class& mint_cls =
Class::Handle(zone, Isolate::Current()->object_store()->mint_class());
mint_cls.set_constants(Object::empty_array());
@ -5101,30 +5085,24 @@ void Deserializer::Deserialize() {
num_base_objects_, next_ref_index_ - 1);
}
{
TIMELINE_DURATION(thread(), Isolate, "ReadAlloc");
for (intptr_t i = 0; i < num_clusters_; i++) {
clusters_[i] = ReadCluster();
clusters_[i]->ReadAlloc(this);
for (intptr_t i = 0; i < num_clusters_; i++) {
clusters_[i] = ReadCluster();
clusters_[i]->ReadAlloc(this);
#if defined(DEBUG)
intptr_t serializers_next_ref_index_ = Read<int32_t>();
ASSERT(serializers_next_ref_index_ == next_ref_index_);
intptr_t serializers_next_ref_index_ = Read<int32_t>();
ASSERT(serializers_next_ref_index_ == next_ref_index_);
#endif
}
}
// We should have completely filled the ref array.
ASSERT((next_ref_index_ - 1) == num_objects_);
{
TIMELINE_DURATION(thread(), Isolate, "ReadFill");
for (intptr_t i = 0; i < num_clusters_; i++) {
clusters_[i]->ReadFill(this);
for (intptr_t i = 0; i < num_clusters_; i++) {
clusters_[i]->ReadFill(this);
#if defined(DEBUG)
int32_t section_marker = Read<int32_t>();
ASSERT(section_marker == kSectionMarker);
int32_t section_marker = Read<int32_t>();
ASSERT(section_marker == kSectionMarker);
#endif
}
}
}
@ -5233,11 +5211,8 @@ void Deserializer::ReadVMSnapshot() {
isolate()->ValidateClassTable();
#endif
{
TIMELINE_DURATION(thread(), Isolate, "PostLoad");
for (intptr_t i = 0; i < num_clusters_; i++) {
clusters_[i]->PostLoad(refs, kind_, zone_);
}
for (intptr_t i = 0; i < num_clusters_; i++) {
clusters_[i]->PostLoad(refs, kind_, zone_);
}
}
@ -5282,11 +5257,8 @@ void Deserializer::ReadIsolateSnapshot(ObjectStore* object_store) {
isolate->heap()->Verify();
#endif
{
TIMELINE_DURATION(thread(), Isolate, "PostLoad");
for (intptr_t i = 0; i < num_clusters_; i++) {
clusters_[i]->PostLoad(refs, kind_, zone_);
}
for (intptr_t i = 0; i < num_clusters_; i++) {
clusters_[i]->PostLoad(refs, kind_, zone_);
}
// Setup native resolver for bootstrap impl.

View file

@ -2295,9 +2295,6 @@ bool PrecompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
}
bool is_compiled = false;
Zone* const zone = thread()->zone();
#ifndef PRODUCT
TimelineStream* compiler_timeline = Timeline::GetCompilerStream();
#endif // !PRODUCT
HANDLESCOPE(thread());
// We may reattempt compilation if the function needs to be assembled using
@ -2323,7 +2320,7 @@ bool PrecompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
{
ic_data_array = new (zone) ZoneGrowableArray<const ICData*>();
TIMELINE_DURATION(thread(), Compiler, "BuildFlowGraph");
TIMELINE_DURATION(thread(), CompilerVerbose, "BuildFlowGraph");
flow_graph =
pipeline->BuildFlowGraph(zone, parsed_function(), ic_data_array,
Compiler::kNoOSRDeoptId, optimized());
@ -2348,10 +2345,9 @@ bool PrecompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
pass_state.block_scheduler = &block_scheduler;
pass_state.reorder_blocks =
FlowGraph::ShouldReorderBlocks(function, optimized());
NOT_IN_PRODUCT(pass_state.compiler_timeline = compiler_timeline);
if (optimized()) {
TIMELINE_DURATION(thread(), Compiler, "OptimizationPasses");
TIMELINE_DURATION(thread(), CompilerVerbose, "OptimizationPasses");
pass_state.inline_id_to_function.Add(&function);
// We do not add the token position now because we don't know the
@ -2395,12 +2391,12 @@ bool PrecompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
pass_state.inline_id_to_token_pos, pass_state.caller_inline_id,
ic_data_array, function_stats);
{
TIMELINE_DURATION(thread(), Compiler, "CompileGraph");
TIMELINE_DURATION(thread(), CompilerVerbose, "CompileGraph");
graph_compiler.CompileGraph();
pipeline->FinalizeCompilation(flow_graph);
}
{
TIMELINE_DURATION(thread(), Compiler, "FinalizeCompilation");
TIMELINE_DURATION(thread(), CompilerVerbose, "FinalizeCompilation");
ASSERT(thread()->IsMutatorThread());
FinalizeCompilation(&assembler, &graph_compiler, flow_graph,
function_stats);

View file

@ -40,7 +40,8 @@ static void TraceStrongModeType(const Instruction* instr,
}
void FlowGraphTypePropagator::Propagate(FlowGraph* flow_graph) {
TIMELINE_DURATION(flow_graph->thread(), Compiler, "FlowGraphTypePropagator");
TIMELINE_DURATION(flow_graph->thread(), CompilerVerbose,
"FlowGraphTypePropagator");
FlowGraphTypePropagator propagator(flow_graph);
propagator.Propagate();
}

View file

@ -173,7 +173,7 @@ void CompilerPass::Run(CompilerPassState* state) const {
PrintGraph(state, kTraceBefore, round);
{
TIMELINE_DURATION(thread, Compiler, name());
TIMELINE_DURATION(thread, CompilerVerbose, name());
repeat = DoBody(state);
DEBUG_ASSERT(state->flow_graph->VerifyUseLists());
thread->CheckForSafepoint();

View file

@ -64,9 +64,6 @@ struct CompilerPassState {
precompiler(precompiler),
inlining_depth(0),
sinking(NULL),
#ifndef PRODUCT
compiler_timeline(NULL),
#endif
call_specializer(NULL),
speculative_policy(speculative_policy),
reorder_blocks(false),
@ -80,8 +77,6 @@ struct CompilerPassState {
int inlining_depth;
AllocationSinking* sinking;
NOT_IN_PRODUCT(TimelineStream* compiler_timeline);
// Maps inline_id_to_function[inline_id] -> function. Top scope
// function has inline_id 0. The map is populated by the inliner.
GrowableArray<const Function*> inline_id_to_function;

View file

@ -310,7 +310,7 @@ void BytecodeMetadataHelper::ReadTypeParametersDeclaration(
void BytecodeMetadataHelper::ReadConstantPool(const Function& function,
const ObjectPool& pool) {
TIMELINE_DURATION(Thread::Current(), Compiler,
TIMELINE_DURATION(Thread::Current(), CompilerVerbose,
"BytecodeMetadataHelper::ReadConstantPool");
// These enums and the code below reading the constant pool from kernel must
@ -639,7 +639,7 @@ void BytecodeMetadataHelper::ReadConstantPool(const Function& function,
}
RawBytecode* BytecodeMetadataHelper::ReadBytecode(const ObjectPool& pool) {
TIMELINE_DURATION(Thread::Current(), Compiler,
TIMELINE_DURATION(Thread::Current(), CompilerVerbose,
"BytecodeMetadataHelper::ReadBytecode");
intptr_t size = helper_->ReadUInt();
intptr_t offset = Utils::RoundUp(helper_->reader_.offset(), sizeof(KBCInstr));
@ -658,7 +658,7 @@ RawBytecode* BytecodeMetadataHelper::ReadBytecode(const ObjectPool& pool) {
void BytecodeMetadataHelper::ReadExceptionsTable(const Bytecode& bytecode,
bool has_exceptions_table) {
TIMELINE_DURATION(Thread::Current(), Compiler,
TIMELINE_DURATION(Thread::Current(), CompilerVerbose,
"BytecodeMetadataHelper::ReadExceptionsTable");
const intptr_t try_block_count =

View file

@ -556,8 +556,6 @@ RawCode* CompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
return Code::null();
}
Zone* const zone = thread()->zone();
NOT_IN_PRODUCT(TimelineStream* compiler_timeline =
Timeline::GetCompilerStream());
HANDLESCOPE(thread());
// We may reattempt compilation if the function needs to be assembled using
@ -618,7 +616,7 @@ RawCode* CompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
}
}
TIMELINE_DURATION(thread(), Compiler, "BuildFlowGraph");
TIMELINE_DURATION(thread(), CompilerVerbose, "BuildFlowGraph");
flow_graph = pipeline->BuildFlowGraph(
zone, parsed_function(), ic_data_array, osr_id(), optimized());
}
@ -636,18 +634,17 @@ RawCode* CompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
const bool reorder_blocks =
FlowGraph::ShouldReorderBlocks(function, optimized());
if (reorder_blocks) {
TIMELINE_DURATION(thread(), Compiler,
TIMELINE_DURATION(thread(), CompilerVerbose,
"BlockScheduler::AssignEdgeWeights");
block_scheduler.AssignEdgeWeights();
}
CompilerPassState pass_state(thread(), flow_graph, &speculative_policy);
NOT_IN_PRODUCT(pass_state.compiler_timeline = compiler_timeline);
pass_state.block_scheduler = &block_scheduler;
pass_state.reorder_blocks = reorder_blocks;
if (optimized()) {
TIMELINE_DURATION(thread(), Compiler, "OptimizationPasses");
TIMELINE_DURATION(thread(), CompilerVerbose, "OptimizationPasses");
pass_state.inline_id_to_function.Add(&function);
// We do not add the token position now because we don't know the
@ -674,12 +671,12 @@ RawCode* CompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
pass_state.inline_id_to_token_pos, pass_state.caller_inline_id,
ic_data_array);
{
TIMELINE_DURATION(thread(), Compiler, "CompileGraph");
TIMELINE_DURATION(thread(), CompilerVerbose, "CompileGraph");
graph_compiler.CompileGraph();
pipeline->FinalizeCompilation(flow_graph);
}
{
TIMELINE_DURATION(thread(), Compiler, "FinalizeCompilation");
TIMELINE_DURATION(thread(), CompilerVerbose, "FinalizeCompilation");
if (thread()->IsMutatorThread()) {
*result =
FinalizeCompilation(&assembler, &graph_compiler, flow_graph);

View file

@ -235,7 +235,7 @@ char* Dart::Init(const uint8_t* vm_isolate_snapshot,
ICData::Init();
if (vm_isolate_snapshot != NULL) {
#if defined(SUPPORT_TIMELINE)
TimelineDurationScope tds(Timeline::GetVMStream(), "VMIsolateSnapshot");
TimelineDurationScope tds(Timeline::GetVMStream(), "ReadVMSnapshot");
#endif
ASSERT(snapshot != nullptr);
vm_snapshot_kind_ = snapshot->kind();
@ -599,10 +599,7 @@ RawError* Dart::InitializeIsolate(const uint8_t* snapshot_data,
ASSERT(I != NULL);
StackZone zone(T);
HandleScope handle_scope(T);
{
TIMELINE_DURATION(T, Isolate, "ObjectStore::Init");
ObjectStore::Init(I);
}
ObjectStore::Init(I);
Error& error = Error::Handle(T->zone());
error = Object::Init(I, kernel_buffer, kernel_buffer_size);
@ -613,7 +610,7 @@ RawError* Dart::InitializeIsolate(const uint8_t* snapshot_data,
// Read the snapshot and setup the initial state.
#if defined(SUPPORT_TIMELINE)
TimelineDurationScope tds(T, Timeline::GetIsolateStream(),
"IsolateSnapshotReader");
"ReadIsolateSnapshot");
#endif
// TODO(turnidge): Remove once length is not part of the snapshot.
const Snapshot* snapshot = Snapshot::SetupFromBuffer(snapshot_data);

View file

@ -589,16 +589,16 @@ void GCMarker::ProcessObjectIdTable() {
#endif // !PRODUCT
}
class MarkTask : public ThreadPool::Task {
class ParallelMarkTask : public ThreadPool::Task {
public:
MarkTask(GCMarker* marker,
Isolate* isolate,
MarkingStack* marking_stack,
ThreadBarrier* barrier,
SyncMarkingVisitor* visitor,
intptr_t task_index,
intptr_t num_tasks,
uintptr_t* num_busy)
ParallelMarkTask(GCMarker* marker,
Isolate* isolate,
MarkingStack* marking_stack,
ThreadBarrier* barrier,
SyncMarkingVisitor* visitor,
intptr_t task_index,
intptr_t num_tasks,
uintptr_t* num_busy)
: marker_(marker),
isolate_(isolate),
marking_stack_(marking_stack),
@ -613,7 +613,7 @@ class MarkTask : public ThreadPool::Task {
Thread::EnterIsolateAsHelper(isolate_, Thread::kMarkerTask, true);
ASSERT(result);
{
TIMELINE_FUNCTION_GC_DURATION(Thread::Current(), "MarkTask");
TIMELINE_FUNCTION_GC_DURATION(Thread::Current(), "ParallelMark");
int64_t start = OS::GetCurrentMonotonicMicros();
// Phase 1: Iterate over roots and drain marking stack in tasks.
@ -705,7 +705,7 @@ class MarkTask : public ThreadPool::Task {
const intptr_t num_tasks_;
uintptr_t* num_busy_;
DISALLOW_COPY_AND_ASSIGN(MarkTask);
DISALLOW_COPY_AND_ASSIGN(ParallelMarkTask);
};
class ConcurrentMarkTask : public ThreadPool::Task {
@ -737,7 +737,7 @@ class ConcurrentMarkTask : public ThreadPool::Task {
Thread::EnterIsolateAsHelper(isolate_, Thread::kMarkerTask, true);
ASSERT(result);
{
TIMELINE_FUNCTION_GC_DURATION(Thread::Current(), "ConcurrentMarkTask");
TIMELINE_FUNCTION_GC_DURATION(Thread::Current(), "ConcurrentMark");
int64_t start = OS::GetCurrentMonotonicMicros();
marker_->IterateRoots(visitor_, task_index_, num_tasks_);
@ -942,11 +942,9 @@ void GCMarker::MarkObjects(PageSpace* page_space, bool collect_code) {
skipped_code_functions);
}
MarkTask* mark_task =
new MarkTask(this, isolate_, &marking_stack_, &barrier, visitor, i,
num_tasks, &num_busy);
ThreadPool* pool = Dart::thread_pool();
bool result = pool->Run(mark_task);
bool result = Dart::thread_pool()->Run(
new ParallelMarkTask(this, isolate_, &marking_stack_, &barrier,
visitor, i, num_tasks, &num_busy));
ASSERT(result);
}
bool more_to_mark = false;

View file

@ -71,7 +71,7 @@ class GCMarker {
int64_t marked_micros_;
friend class ConcurrentMarkTask;
friend class MarkTask;
friend class ParallelMarkTask;
DISALLOW_IMPLICIT_CONSTRUCTORS(GCMarker);
};

View file

@ -518,7 +518,7 @@ class PageSpace {
friend class ExclusiveLargePageIterator;
friend class HeapIterationScope;
friend class PageSpaceController;
friend class SweeperTask;
friend class ConcurrentSweeperTask;
friend class GCCompactor;
friend class CompactorTask;

View file

@ -104,13 +104,13 @@ intptr_t GCSweeper::SweepLargePage(HeapPage* page) {
return words_to_end;
}
class SweeperTask : public ThreadPool::Task {
class ConcurrentSweeperTask : public ThreadPool::Task {
public:
SweeperTask(Isolate* isolate,
PageSpace* old_space,
HeapPage* first,
HeapPage* last,
FreeList* freelist)
ConcurrentSweeperTask(Isolate* isolate,
PageSpace* old_space,
HeapPage* first,
HeapPage* last,
FreeList* freelist)
: task_isolate_(isolate),
old_space_(old_space),
first_(first),
@ -132,7 +132,7 @@ class SweeperTask : public ThreadPool::Task {
ASSERT(result);
{
Thread* thread = Thread::Current();
TIMELINE_FUNCTION_GC_DURATION(thread, "SweeperTask");
TIMELINE_FUNCTION_GC_DURATION(thread, "ConcurrentSweep");
GCSweeper sweeper;
HeapPage* page = first_;
@ -182,10 +182,9 @@ void GCSweeper::SweepConcurrent(Isolate* isolate,
HeapPage* first,
HeapPage* last,
FreeList* freelist) {
SweeperTask* task = new SweeperTask(isolate, isolate->heap()->old_space(),
first, last, freelist);
ThreadPool* pool = Dart::thread_pool();
pool->Run(task);
bool result = Dart::thread_pool()->Run(new ConcurrentSweeperTask(
isolate, isolate->heap()->old_space(), first, last, freelist));
ASSERT(result);
}
} // namespace dart

View file

@ -211,6 +211,7 @@ void KernelLoader::ReadObfuscationProhibitions() {
Object& KernelLoader::LoadEntireProgram(Program* program,
bool process_pending_classes) {
Thread* thread = Thread::Current();
TIMELINE_DURATION(thread, Isolate, "LoadKernel");
if (program->is_single_program()) {
KernelLoader loader(program);
@ -1337,6 +1338,8 @@ void KernelLoader::FinishClassLoading(const Class& klass,
intptr_t class_offset,
const ClassIndex& class_index,
ClassHelper* class_helper) {
TIMELINE_DURATION(Thread::Current(), Isolate, "FinishClassLoading");
fields_.Clear();
functions_.Clear();
ActiveClassScope active_class_scope(&active_class_, &klass);

View file

@ -47,8 +47,8 @@ DEFINE_FLAG(charp,
timeline_streams,
NULL,
"Comma separated list of timeline streams to record. "
"Valid values: all, API, Compiler, Dart, Debugger, Embedder, "
"GC, Isolate, and VM.");
"Valid values: all, API, Compiler, CompilerVerbose, Dart, "
"Debugger, Embedder, GC, Isolate, and VM.");
DEFINE_FLAG(charp,
timeline_recorder,
"ring",

View file

@ -34,6 +34,7 @@ class Zone;
#define TIMELINE_STREAM_LIST(V) \
V(API, false) \
V(Compiler, false) \
V(CompilerVerbose, false) \
V(Dart, false) \
V(Debugger, false) \
V(Embedder, false) \