From 39dc9d8a7db7e4228be214230e5ece4dcce10620 Mon Sep 17 00:00:00 2001 From: Vyacheslav Egorov Date: Thu, 27 Mar 2025 06:44:23 -0700 Subject: [PATCH] [vm] Intern callstacks when writing Perfetto profile This significantly reduces the space occupied by callstacks e.g. 5 second recording of fibonacci computation goes from 1.5Mb to 600Kb. Also fixes flakiness of pkg/vm_service/test/get_perfetto_cpu_samples_rpc_test. Fixes https://github.com/dart-lang/sdk/issues/54401 Fixes https://github.com/dart-lang/sdk/issues/60413 This relands commit f07915cb6e9da7efd5ad66a81d597ec5fa595440 with a fix for Android build. TEST=ci Change-Id: Id182692d30e953b20ad2f6ade587e4036fac7e7d Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/418221 Reviewed-by: Martin Kustermann Commit-Queue: Slava Egorov --- .../get_perfetto_cpu_samples_rpc_test.dart | 49 +++++++++- runtime/vm/profiler_service.cc | 91 +++++++++---------- runtime/vm/profiler_service.h | 7 -- 3 files changed, 91 insertions(+), 56 deletions(-) diff --git a/pkg/vm_service/test/get_perfetto_cpu_samples_rpc_test.dart b/pkg/vm_service/test/get_perfetto_cpu_samples_rpc_test.dart index b94ea70afc3..8ff3f85f298 100644 --- a/pkg/vm_service/test/get_perfetto_cpu_samples_rpc_test.dart +++ b/pkg/vm_service/test/get_perfetto_cpu_samples_rpc_test.dart @@ -63,6 +63,19 @@ Iterable extractPerfSamplesFromTracePackets( final tests = [ hasStoppedAtExit, (VmService service, IsolateRef isolateRef) async { + // This test is calling |getPerfettoCpuSamples| twice: with and without + // filter and expects to get consistent results. However profiler will + // continue running and recording samples while this is happening which + // means the buffer can overflow and old samples will be lost. + // + // The best way to avoid this would be to pause the profiler, but + // service API does not provide a way to do it: setting profiler flag to + // false will stop profiler entirely and discard accumulated samples. + // + // Instead we resort to bumping profile_period to 1h to stabilize this + // test. + await service.setFlag('profile_period', '60000000'); + final result = await service.getPerfettoCpuSamples(isolateRef.id!); expect(result.type, 'PerfettoCpuSamples'); expect(result.samplePeriod, isPositive); @@ -77,18 +90,52 @@ final tests = [ int frameCount = 0; int callstackCount = 0; int perfSampleCount = 0; + final seenFrames = {}; + final seenCallstacks = {}; for (final packet in packets) { + if (packet.sequenceFlags & + TracePacket_SequenceFlags.SEQ_INCREMENTAL_STATE_CLEARED.value != + 0) { + seenCallstacks.clear(); + } + if (packet.hasInternedData()) { frameCount += packet.internedData.frames.length; callstackCount += packet.internedData.callstacks.length; + + for (var frame in packet.internedData.frames) { + expect(frame.iid.toInt(), isNot(0)); + seenFrames.add(frame.iid.toInt()); + } + for (var callstack in packet.internedData.callstacks) { + for (var frame in callstack.frameIds) { + expect(frame.toInt(), isIn(seenFrames)); + } + + expect(callstack.iid.toInt(), isNot(0)); + seenCallstacks.add(callstack.iid.toInt()); + } } if (packet.hasPerfSample()) { perfSampleCount += 1; + + // Check that packet correctly indicates dependency on incremental + // state and that incremental state contains interned callstack + // for this sample. + expect( + packet.sequenceFlags & + TracePacket_SequenceFlags.SEQ_NEEDS_INCREMENTAL_STATE.value != + 0, + isTrue, + ); + expect(packet.perfSample.callstackIid.toInt(), isIn(seenCallstacks)); } } expect(frameCount, isPositive); expect(callstackCount, isPositive); - expect(perfSampleCount, callstackCount); + // Note: we will have more perfSampleCount than we have callstacks because + // callstacks are interned. + expect(perfSampleCount, greaterThanOrEqualTo(callstackCount)); // Calculate the time window of events. final timeOriginNanos = computeTimeOriginNanos(packets); diff --git a/runtime/vm/profiler_service.cc b/runtime/vm/profiler_service.cc index 452e5cfd6b9..a220e9d020d 100644 --- a/runtime/vm/profiler_service.cc +++ b/runtime/vm/profiler_service.cc @@ -1665,13 +1665,14 @@ void Profile::ProcessSampleFrameJSON(JSONArray* stack, } #if defined(SUPPORT_PERFETTO) && !defined(PRODUCT) -void Profile::ProcessSampleFramePerfetto( - perfetto::protos::pbzero::Callstack* callstack, - ProfileCodeInlinedFunctionsCache* cache, - ProcessedSample* sample, - intptr_t frame_index) { +namespace { +void ProcessSampleFramePerfetto(Profile* profile, + GrowableArray& callstack, + ProfileCodeInlinedFunctionsCache* cache, + ProcessedSample* sample, + intptr_t frame_index) { const uword pc = sample->At(frame_index); - ProfileCode* profile_code = GetCodeFromPC(pc, sample->timestamp()); + ProfileCode* profile_code = profile->GetCodeFromPC(pc, sample->timestamp()); ASSERT(profile_code != nullptr); ProfileFunction* function = profile_code->function(); ASSERT(function != nullptr); @@ -1691,14 +1692,6 @@ void Profile::ProcessSampleFramePerfetto( code ^= profile_code->code().ptr(); cache->Get(pc, code, sample, frame_index, &inlined_functions, &inlined_token_positions, &token_position); - if (FLAG_trace_profiler_verbose && (inlined_functions != NULL)) { - for (intptr_t i = 0; i < inlined_functions->length(); i++) { - const String& name = - String::Handle((*inlined_functions)[i]->QualifiedScrubbedName()); - THR_Print("InlinedFunction[%" Pd "] = {%s, %s}\n", i, name.ToCString(), - (*inlined_token_positions)[i].ToCString()); - } - } } if (code.IsNull() || (inlined_functions == nullptr) || @@ -1706,36 +1699,21 @@ void Profile::ProcessSampleFramePerfetto( // This is the ID of a |Frame| that was added to the interned data table in // |ProfilerService::PrintProfilePerfetto|. See the comments in that method // for more details. - callstack->add_frame_ids(function->table_index() + 1); + callstack.Add(function->table_index() + 1); return; } - if (!code.is_optimized()) { - OS::PrintErr("Code that should be optimized is not. Please file a bug\n"); - OS::PrintErr("Code object: %s\n", code.ToCString()); - OS::PrintErr("Inlined functions length: %" Pd "\n", - inlined_functions->length()); - for (intptr_t i = 0; i < inlined_functions->length(); i++) { - OS::PrintErr("IF[%" Pd "] = %s\n", i, - (*inlined_functions)[i]->ToFullyQualifiedCString()); - } - } - - ASSERT(code.is_optimized()); - for (intptr_t i = 0; i < inlined_functions->length(); ++i) { const Function* inlined_function = (*inlined_functions)[i]; ASSERT(inlined_function != NULL); ASSERT(!inlined_function->IsNull()); ProfileFunction* profile_function = - functions_->LookupOrAdd(*inlined_function); + profile->FindFunction(*inlined_function); ASSERT(profile_function != NULL); - // This is the ID of a |Frame| that was added to the interned data table in - // |ProfilerService::PrintProfilePerfetto|. See the comments in that method - // for more details. - callstack->add_frame_ids(profile_function->table_index() + 1); + callstack.Add(profile_function->table_index() + 1); } } +} // namespace #endif // defined(SUPPORT_PERFETTO) && !defined(PRODUCT) void Profile::ProcessInlinedFunctionFrameJSON( @@ -1824,6 +1802,9 @@ void Profile::PrintSamplesPerfetto( ASSERT(packet_ptr != nullptr); auto& packet = *packet_ptr; + perfetto_utils::BytesInterner callstack_interner(zone_); + GrowableArray callstack(128); + // Note that |cache| is zone-allocated, so it does not need to be deallocated // manually. auto* cache = new ProfileCodeInlinedFunctionsCache(); @@ -1831,6 +1812,22 @@ void Profile::PrintSamplesPerfetto( ++sample_index) { ProcessedSample* sample = samples_->At(sample_index); + // Walk the sampled PCs and intern the stack. + callstack.Clear(); + for (intptr_t frame_index = sample->length() - 1; frame_index >= 0; + --frame_index) { + ASSERT(sample->At(frame_index) != 0); + ProcessSampleFramePerfetto(this, callstack, cache, sample, frame_index); + } + + // Empty sample (everything is invisible). + if (callstack.is_empty()) { + continue; + } + + const auto callstack_iid = + callstack_interner.Intern(&callstack[0], callstack.length()); + perfetto_utils::SetTrustedPacketSequenceId(packet.get()); // We set this flag to indicate that this packet reads from the interned // data table. @@ -1840,27 +1837,25 @@ void Profile::PrintSamplesPerfetto( perfetto_utils::SetTimestampAndMonotonicClockId(packet.get(), sample->timestamp()); - const intptr_t callstack_iid = sample_index + 1; - // Add a |Callstack| to the interned data table that represents the stack - // trace stored in |sample|. - perfetto::protos::pbzero::Callstack* callstack = - packet->set_interned_data()->add_callstacks(); - callstack->set_iid(callstack_iid); - // Walk the sampled PCs. - for (intptr_t frame_index = sample->length() - 1; frame_index >= 0; - --frame_index) { - ASSERT(sample->At(frame_index) != 0); - ProcessSampleFramePerfetto(callstack, cache, sample, frame_index); - } - // Populate |packet| with a |PerfSample| that is linked to the |Callstack| // that we populated above. - perfetto::protos::pbzero::PerfSample& perf_sample = - *packet->set_perf_sample(); + auto& perf_sample = *packet->set_perf_sample(); perf_sample.set_pid(OS::ProcessId()); perf_sample.set_tid(OSThread::ThreadIdToIntPtr(sample->tid())); perf_sample.set_callstack_iid(callstack_iid); + if (callstack_interner.HasNewlyInternedEntries()) { + auto& interned_data = *packet->set_interned_data(); + callstack_interner.FlushNewlyInternedTo( + [&interned_data](const auto& interned) { + auto& callstack = *interned_data.add_callstacks(); + callstack.set_iid(interned.iid); + for (intptr_t i = 0; i < interned.length; i++) { + callstack.add_frame_ids(interned.data[i]); + } + }); + } + perfetto_utils::AppendPacketToJSONBase64String(jsonBase64String, &packet); packet.Reset(); } diff --git a/runtime/vm/profiler_service.h b/runtime/vm/profiler_service.h index 465b1f56523..c713b777a7b 100644 --- a/runtime/vm/profiler_service.h +++ b/runtime/vm/profiler_service.h @@ -406,13 +406,6 @@ class Profile : public ValueObject { ProfileCodeInlinedFunctionsCache* cache, ProcessedSample* sample, intptr_t frame_index); -#if defined(SUPPORT_PERFETTO) && !defined(PRODUCT) - void ProcessSampleFramePerfetto( - perfetto::protos::pbzero::Callstack* callstack, - ProfileCodeInlinedFunctionsCache* cache, - ProcessedSample* sample, - intptr_t frame_index); -#endif // defined(SUPPORT_PERFETTO) && !defined(PRODUCT) void ProcessInlinedFunctionFrameJSON(JSONArray* stack, const Function* inlined_function); void PrintFunctionFrameIndexJSON(JSONArray* stack, ProfileFunction* function);