Skip to content

Commit 169331a

Browse files
rmacnak-googlecommit-bot@chromium.org
rmacnak-google
authored and
commit-bot@chromium.org
committed
[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>
1 parent 874f9d0 commit 169331a

16 files changed

Lines changed: 76 additions & 108 deletions

‎runtime/vm/class_finalizer.cc‎

Lines changed: 12 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1116,17 +1116,26 @@ void ClassFinalizer::FinalizeTypesInClass(const Class& cls) {
11161116
}
11171117

11181118
void ClassFinalizer::FinalizeClass(const Class& cls) {
1119-
Thread* thread = Thread::Current();
1120-
HANDLESCOPE(thread);
11211119
ASSERT(cls.is_type_finalized());
11221120
if (cls.is_finalized()) {
11231121
return;
11241122
}
1123+
1124+
Thread* thread = Thread::Current();
1125+
HANDLESCOPE(thread);
1126+
11251127
if (FLAG_trace_class_finalization) {
11261128
THR_Print("Finalize %s\n", cls.ToCString());
11271129
}
11281130

1129-
TIMELINE_DURATION(thread, Compiler, "ClassFinalizer::FinalizeClass");
1131+
#if defined(SUPPORT_TIMELINE)
1132+
TimelineDurationScope tds(thread, Timeline::GetCompilerStream(),
1133+
"FinalizeClass");
1134+
if (tds.enabled()) {
1135+
tds.SetNumArguments(1);
1136+
tds.CopyArgument(0, "class", cls.ToCString());
1137+
}
1138+
#endif // defined(SUPPORT_TIMELINE)
11301139

11311140
#if !defined(DART_PRECOMPILED_RUNTIME)
11321141
// If loading from a kernel, make sure that the class is fully loaded.

‎runtime/vm/clustered_snapshot.cc‎

Lines changed: 13 additions & 41 deletions
Original file line numberDiff line numberDiff line change
@@ -593,8 +593,6 @@ class FunctionDeserializationCluster : public DeserializationCluster {
593593
}
594594

595595
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
596-
TIMELINE_DURATION(Thread::Current(), Isolate, "Function");
597-
598596
if (kind == Snapshot::kFullAOT) {
599597
Function& func = Function::Handle(zone);
600598
for (intptr_t i = start_index_; i < stop_index_; i++) {
@@ -1006,8 +1004,6 @@ class FieldDeserializationCluster : public DeserializationCluster {
10061004
}
10071005

10081006
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
1009-
TIMELINE_DURATION(Thread::Current(), Isolate, "Field");
1010-
10111007
Field& field = Field::Handle(zone);
10121008
if (!Isolate::Current()->use_field_guards()) {
10131009
for (intptr_t i = start_index_; i < stop_index_; i++) {
@@ -1319,8 +1315,6 @@ class KernelProgramInfoDeserializationCluster : public DeserializationCluster {
13191315
}
13201316

13211317
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
1322-
TIMELINE_DURATION(Thread::Current(), Isolate, "KernelProgramInfo");
1323-
13241318
Array& array = Array::Handle(zone);
13251319
KernelProgramInfo& info = KernelProgramInfo::Handle(zone);
13261320
for (intptr_t id = start_index_; id < stop_index_; id++) {
@@ -2332,8 +2326,6 @@ class MegamorphicCacheDeserializationCluster : public DeserializationCluster {
23322326
}
23332327

23342328
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
2335-
TIMELINE_DURATION(Thread::Current(), Isolate, "MegamorphicCache");
2336-
23372329
#if defined(DART_PRECOMPILED_RUNTIME)
23382330
if (FLAG_use_bare_instructions) {
23392331
// By default, every megamorphic call site will load the target
@@ -2869,8 +2861,6 @@ class TypeDeserializationCluster : public DeserializationCluster {
28692861
}
28702862

28712863
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
2872-
TIMELINE_DURATION(Thread::Current(), Isolate, "Type");
2873-
28742864
Type& type = Type::Handle(zone);
28752865
Code& stub = Code::Handle(zone);
28762866

@@ -2969,8 +2959,6 @@ class TypeRefDeserializationCluster : public DeserializationCluster {
29692959
}
29702960

29712961
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
2972-
TIMELINE_DURATION(Thread::Current(), Isolate, "TypeRef");
2973-
29742962
TypeRef& type_ref = TypeRef::Handle(zone);
29752963
Code& stub = Code::Handle(zone);
29762964

@@ -3065,8 +3053,6 @@ class TypeParameterDeserializationCluster : public DeserializationCluster {
30653053
}
30663054

30673055
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
3068-
TIMELINE_DURATION(Thread::Current(), Isolate, "TypeParameter");
3069-
30703056
TypeParameter& type_param = TypeParameter::Handle(zone);
30713057
Code& stub = Code::Handle(zone);
30723058

@@ -3228,8 +3214,6 @@ class MintDeserializationCluster : public DeserializationCluster {
32283214
void ReadFill(Deserializer* d) {}
32293215

32303216
void PostLoad(const Array& refs, Snapshot::Kind kind, Zone* zone) {
3231-
TIMELINE_DURATION(Thread::Current(), Isolate, "Mint");
3232-
32333217
const Class& mint_cls =
32343218
Class::Handle(zone, Isolate::Current()->object_store()->mint_class());
32353219
mint_cls.set_constants(Object::empty_array());
@@ -5101,30 +5085,24 @@ void Deserializer::Deserialize() {
51015085
num_base_objects_, next_ref_index_ - 1);
51025086
}
51035087

5104-
{
5105-
TIMELINE_DURATION(thread(), Isolate, "ReadAlloc");
5106-
for (intptr_t i = 0; i < num_clusters_; i++) {
5107-
clusters_[i] = ReadCluster();
5108-
clusters_[i]->ReadAlloc(this);
5088+
for (intptr_t i = 0; i < num_clusters_; i++) {
5089+
clusters_[i] = ReadCluster();
5090+
clusters_[i]->ReadAlloc(this);
51095091
#if defined(DEBUG)
5110-
intptr_t serializers_next_ref_index_ = Read<int32_t>();
5111-
ASSERT(serializers_next_ref_index_ == next_ref_index_);
5092+
intptr_t serializers_next_ref_index_ = Read<int32_t>();
5093+
ASSERT(serializers_next_ref_index_ == next_ref_index_);
51125094
#endif
5113-
}
51145095
}
51155096

51165097
// We should have completely filled the ref array.
51175098
ASSERT((next_ref_index_ - 1) == num_objects_);
51185099

5119-
{
5120-
TIMELINE_DURATION(thread(), Isolate, "ReadFill");
5121-
for (intptr_t i = 0; i < num_clusters_; i++) {
5122-
clusters_[i]->ReadFill(this);
5100+
for (intptr_t i = 0; i < num_clusters_; i++) {
5101+
clusters_[i]->ReadFill(this);
51235102
#if defined(DEBUG)
5124-
int32_t section_marker = Read<int32_t>();
5125-
ASSERT(section_marker == kSectionMarker);
5103+
int32_t section_marker = Read<int32_t>();
5104+
ASSERT(section_marker == kSectionMarker);
51265105
#endif
5127-
}
51285106
}
51295107
}
51305108

@@ -5233,11 +5211,8 @@ void Deserializer::ReadVMSnapshot() {
52335211
isolate()->ValidateClassTable();
52345212
#endif
52355213

5236-
{
5237-
TIMELINE_DURATION(thread(), Isolate, "PostLoad");
5238-
for (intptr_t i = 0; i < num_clusters_; i++) {
5239-
clusters_[i]->PostLoad(refs, kind_, zone_);
5240-
}
5214+
for (intptr_t i = 0; i < num_clusters_; i++) {
5215+
clusters_[i]->PostLoad(refs, kind_, zone_);
52415216
}
52425217
}
52435218

@@ -5282,11 +5257,8 @@ void Deserializer::ReadIsolateSnapshot(ObjectStore* object_store) {
52825257
isolate->heap()->Verify();
52835258
#endif
52845259

5285-
{
5286-
TIMELINE_DURATION(thread(), Isolate, "PostLoad");
5287-
for (intptr_t i = 0; i < num_clusters_; i++) {
5288-
clusters_[i]->PostLoad(refs, kind_, zone_);
5289-
}
5260+
for (intptr_t i = 0; i < num_clusters_; i++) {
5261+
clusters_[i]->PostLoad(refs, kind_, zone_);
52905262
}
52915263

52925264
// Setup native resolver for bootstrap impl.

‎runtime/vm/compiler/aot/precompiler.cc‎

Lines changed: 4 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -2295,9 +2295,6 @@ bool PrecompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
22952295
}
22962296
bool is_compiled = false;
22972297
Zone* const zone = thread()->zone();
2298-
#ifndef PRODUCT
2299-
TimelineStream* compiler_timeline = Timeline::GetCompilerStream();
2300-
#endif // !PRODUCT
23012298
HANDLESCOPE(thread());
23022299

23032300
// We may reattempt compilation if the function needs to be assembled using
@@ -2323,7 +2320,7 @@ bool PrecompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
23232320
{
23242321
ic_data_array = new (zone) ZoneGrowableArray<const ICData*>();
23252322

2326-
TIMELINE_DURATION(thread(), Compiler, "BuildFlowGraph");
2323+
TIMELINE_DURATION(thread(), CompilerVerbose, "BuildFlowGraph");
23272324
flow_graph =
23282325
pipeline->BuildFlowGraph(zone, parsed_function(), ic_data_array,
23292326
Compiler::kNoOSRDeoptId, optimized());
@@ -2348,10 +2345,9 @@ bool PrecompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
23482345
pass_state.block_scheduler = &block_scheduler;
23492346
pass_state.reorder_blocks =
23502347
FlowGraph::ShouldReorderBlocks(function, optimized());
2351-
NOT_IN_PRODUCT(pass_state.compiler_timeline = compiler_timeline);
23522348

23532349
if (optimized()) {
2354-
TIMELINE_DURATION(thread(), Compiler, "OptimizationPasses");
2350+
TIMELINE_DURATION(thread(), CompilerVerbose, "OptimizationPasses");
23552351

23562352
pass_state.inline_id_to_function.Add(&function);
23572353
// We do not add the token position now because we don't know the
@@ -2395,12 +2391,12 @@ bool PrecompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
23952391
pass_state.inline_id_to_token_pos, pass_state.caller_inline_id,
23962392
ic_data_array, function_stats);
23972393
{
2398-
TIMELINE_DURATION(thread(), Compiler, "CompileGraph");
2394+
TIMELINE_DURATION(thread(), CompilerVerbose, "CompileGraph");
23992395
graph_compiler.CompileGraph();
24002396
pipeline->FinalizeCompilation(flow_graph);
24012397
}
24022398
{
2403-
TIMELINE_DURATION(thread(), Compiler, "FinalizeCompilation");
2399+
TIMELINE_DURATION(thread(), CompilerVerbose, "FinalizeCompilation");
24042400
ASSERT(thread()->IsMutatorThread());
24052401
FinalizeCompilation(&assembler, &graph_compiler, flow_graph,
24062402
function_stats);

‎runtime/vm/compiler/backend/type_propagator.cc‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,8 @@ static void TraceStrongModeType(const Instruction* instr,
4040
}
4141

4242
void FlowGraphTypePropagator::Propagate(FlowGraph* flow_graph) {
43-
TIMELINE_DURATION(flow_graph->thread(), Compiler, "FlowGraphTypePropagator");
43+
TIMELINE_DURATION(flow_graph->thread(), CompilerVerbose,
44+
"FlowGraphTypePropagator");
4445
FlowGraphTypePropagator propagator(flow_graph);
4546
propagator.Propagate();
4647
}

‎runtime/vm/compiler/compiler_pass.cc‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -173,7 +173,7 @@ void CompilerPass::Run(CompilerPassState* state) const {
173173

174174
PrintGraph(state, kTraceBefore, round);
175175
{
176-
TIMELINE_DURATION(thread, Compiler, name());
176+
TIMELINE_DURATION(thread, CompilerVerbose, name());
177177
repeat = DoBody(state);
178178
DEBUG_ASSERT(state->flow_graph->VerifyUseLists());
179179
thread->CheckForSafepoint();

‎runtime/vm/compiler/compiler_pass.h‎

Lines changed: 0 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -64,9 +64,6 @@ struct CompilerPassState {
6464
precompiler(precompiler),
6565
inlining_depth(0),
6666
sinking(NULL),
67-
#ifndef PRODUCT
68-
compiler_timeline(NULL),
69-
#endif
7067
call_specializer(NULL),
7168
speculative_policy(speculative_policy),
7269
reorder_blocks(false),
@@ -80,8 +77,6 @@ struct CompilerPassState {
8077
int inlining_depth;
8178
AllocationSinking* sinking;
8279

83-
NOT_IN_PRODUCT(TimelineStream* compiler_timeline);
84-
8580
// Maps inline_id_to_function[inline_id] -> function. Top scope
8681
// function has inline_id 0. The map is populated by the inliner.
8782
GrowableArray<const Function*> inline_id_to_function;

‎runtime/vm/compiler/frontend/bytecode_reader.cc‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -310,7 +310,7 @@ void BytecodeMetadataHelper::ReadTypeParametersDeclaration(
310310

311311
void BytecodeMetadataHelper::ReadConstantPool(const Function& function,
312312
const ObjectPool& pool) {
313-
TIMELINE_DURATION(Thread::Current(), Compiler,
313+
TIMELINE_DURATION(Thread::Current(), CompilerVerbose,
314314
"BytecodeMetadataHelper::ReadConstantPool");
315315

316316
// These enums and the code below reading the constant pool from kernel must
@@ -639,7 +639,7 @@ void BytecodeMetadataHelper::ReadConstantPool(const Function& function,
639639
}
640640

641641
RawBytecode* BytecodeMetadataHelper::ReadBytecode(const ObjectPool& pool) {
642-
TIMELINE_DURATION(Thread::Current(), Compiler,
642+
TIMELINE_DURATION(Thread::Current(), CompilerVerbose,
643643
"BytecodeMetadataHelper::ReadBytecode");
644644
intptr_t size = helper_->ReadUInt();
645645
intptr_t offset = Utils::RoundUp(helper_->reader_.offset(), sizeof(KBCInstr));
@@ -658,7 +658,7 @@ RawBytecode* BytecodeMetadataHelper::ReadBytecode(const ObjectPool& pool) {
658658

659659
void BytecodeMetadataHelper::ReadExceptionsTable(const Bytecode& bytecode,
660660
bool has_exceptions_table) {
661-
TIMELINE_DURATION(Thread::Current(), Compiler,
661+
TIMELINE_DURATION(Thread::Current(), CompilerVerbose,
662662
"BytecodeMetadataHelper::ReadExceptionsTable");
663663

664664
const intptr_t try_block_count =

‎runtime/vm/compiler/jit/compiler.cc‎

Lines changed: 5 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -556,8 +556,6 @@ RawCode* CompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
556556
return Code::null();
557557
}
558558
Zone* const zone = thread()->zone();
559-
NOT_IN_PRODUCT(TimelineStream* compiler_timeline =
560-
Timeline::GetCompilerStream());
561559
HANDLESCOPE(thread());
562560

563561
// We may reattempt compilation if the function needs to be assembled using
@@ -618,7 +616,7 @@ RawCode* CompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
618616
}
619617
}
620618

621-
TIMELINE_DURATION(thread(), Compiler, "BuildFlowGraph");
619+
TIMELINE_DURATION(thread(), CompilerVerbose, "BuildFlowGraph");
622620
flow_graph = pipeline->BuildFlowGraph(
623621
zone, parsed_function(), ic_data_array, osr_id(), optimized());
624622
}
@@ -636,18 +634,17 @@ RawCode* CompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
636634
const bool reorder_blocks =
637635
FlowGraph::ShouldReorderBlocks(function, optimized());
638636
if (reorder_blocks) {
639-
TIMELINE_DURATION(thread(), Compiler,
637+
TIMELINE_DURATION(thread(), CompilerVerbose,
640638
"BlockScheduler::AssignEdgeWeights");
641639
block_scheduler.AssignEdgeWeights();
642640
}
643641

644642
CompilerPassState pass_state(thread(), flow_graph, &speculative_policy);
645-
NOT_IN_PRODUCT(pass_state.compiler_timeline = compiler_timeline);
646643
pass_state.block_scheduler = &block_scheduler;
647644
pass_state.reorder_blocks = reorder_blocks;
648645

649646
if (optimized()) {
650-
TIMELINE_DURATION(thread(), Compiler, "OptimizationPasses");
647+
TIMELINE_DURATION(thread(), CompilerVerbose, "OptimizationPasses");
651648

652649
pass_state.inline_id_to_function.Add(&function);
653650
// We do not add the token position now because we don't know the
@@ -674,12 +671,12 @@ RawCode* CompileParsedFunctionHelper::Compile(CompilationPipeline* pipeline) {
674671
pass_state.inline_id_to_token_pos, pass_state.caller_inline_id,
675672
ic_data_array);
676673
{
677-
TIMELINE_DURATION(thread(), Compiler, "CompileGraph");
674+
TIMELINE_DURATION(thread(), CompilerVerbose, "CompileGraph");
678675
graph_compiler.CompileGraph();
679676
pipeline->FinalizeCompilation(flow_graph);
680677
}
681678
{
682-
TIMELINE_DURATION(thread(), Compiler, "FinalizeCompilation");
679+
TIMELINE_DURATION(thread(), CompilerVerbose, "FinalizeCompilation");
683680
if (thread()->IsMutatorThread()) {
684681
*result =
685682
FinalizeCompilation(&assembler, &graph_compiler, flow_graph);

‎runtime/vm/dart.cc‎

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -235,7 +235,7 @@ char* Dart::Init(const uint8_t* vm_isolate_snapshot,
235235
ICData::Init();
236236
if (vm_isolate_snapshot != NULL) {
237237
#if defined(SUPPORT_TIMELINE)
238-
TimelineDurationScope tds(Timeline::GetVMStream(), "VMIsolateSnapshot");
238+
TimelineDurationScope tds(Timeline::GetVMStream(), "ReadVMSnapshot");
239239
#endif
240240
ASSERT(snapshot != nullptr);
241241
vm_snapshot_kind_ = snapshot->kind();
@@ -599,10 +599,7 @@ RawError* Dart::InitializeIsolate(const uint8_t* snapshot_data,
599599
ASSERT(I != NULL);
600600
StackZone zone(T);
601601
HandleScope handle_scope(T);
602-
{
603-
TIMELINE_DURATION(T, Isolate, "ObjectStore::Init");
604-
ObjectStore::Init(I);
605-
}
602+
ObjectStore::Init(I);
606603

607604
Error& error = Error::Handle(T->zone());
608605
error = Object::Init(I, kernel_buffer, kernel_buffer_size);
@@ -613,7 +610,7 @@ RawError* Dart::InitializeIsolate(const uint8_t* snapshot_data,
613610
// Read the snapshot and setup the initial state.
614611
#if defined(SUPPORT_TIMELINE)
615612
TimelineDurationScope tds(T, Timeline::GetIsolateStream(),
616-
"IsolateSnapshotReader");
613+
"ReadIsolateSnapshot");
617614
#endif
618615
// TODO(turnidge): Remove once length is not part of the snapshot.
619616
const Snapshot* snapshot = Snapshot::SetupFromBuffer(snapshot_data);

0 commit comments

Comments
 (0)