diff --git a/runtime/lib/timeline.cc b/runtime/lib/timeline.cc index e90b730061b..64e63d68a0a 100644 --- a/runtime/lib/timeline.cc +++ b/runtime/lib/timeline.cc @@ -36,12 +36,13 @@ DEFINE_NATIVE_ENTRY(Timeline_getTraceClock, 0, 0) { return Integer::New(OS::GetCurrentMonotonicMicros(), Heap::kNew); } -DEFINE_NATIVE_ENTRY(Timeline_reportTaskEvent, 0, 4) { +DEFINE_NATIVE_ENTRY(Timeline_reportTaskEvent, 0, 5) { #if defined(SUPPORT_TIMELINE) GET_NON_NULL_NATIVE_ARGUMENT(Integer, id, arguments->NativeArgAt(0)); - GET_NON_NULL_NATIVE_ARGUMENT(Smi, type, arguments->NativeArgAt(1)); - GET_NON_NULL_NATIVE_ARGUMENT(String, name, arguments->NativeArgAt(2)); - GET_NON_NULL_NATIVE_ARGUMENT(String, args, arguments->NativeArgAt(3)); + GET_NON_NULL_NATIVE_ARGUMENT(Integer, flow_id, arguments->NativeArgAt(1)); + GET_NON_NULL_NATIVE_ARGUMENT(Smi, type, arguments->NativeArgAt(2)); + GET_NON_NULL_NATIVE_ARGUMENT(String, name, arguments->NativeArgAt(3)); + GET_NON_NULL_NATIVE_ARGUMENT(String, args, arguments->NativeArgAt(4)); TimelineEventRecorder* recorder = Timeline::recorder(); if (recorder == nullptr) { @@ -55,8 +56,8 @@ DEFINE_NATIVE_ENTRY(Timeline_reportTaskEvent, 0, 4) { } DartTimelineEventHelpers::ReportTaskEvent( - event, id.AsInt64Value(), type.Value(), name.ToMallocCString(), - args.ToMallocCString()); + event, id.AsInt64Value(), flow_id.AsInt64Value(), type.Value(), + name.ToMallocCString(), args.ToMallocCString()); #endif // SUPPORT_TIMELINE return Object::null(); } diff --git a/runtime/vm/bootstrap_natives.h b/runtime/vm/bootstrap_natives.h index fddfda7b020..433e7d44464 100644 --- a/runtime/vm/bootstrap_natives.h +++ b/runtime/vm/bootstrap_natives.h @@ -155,7 +155,7 @@ namespace dart { V(Timeline_getNextTaskId, 0) \ V(Timeline_getTraceClock, 0) \ V(Timeline_isDartStreamEnabled, 0) \ - V(Timeline_reportTaskEvent, 4) \ + V(Timeline_reportTaskEvent, 5) \ V(TypedData_Int8Array_new, 2) \ V(TypedData_Uint8Array_new, 2) \ V(TypedData_Uint8ClampedArray_new, 2) \ diff --git a/runtime/vm/dart_api_impl.cc b/runtime/vm/dart_api_impl.cc index a97b7ccda73..03c8d81a4c9 100644 --- a/runtime/vm/dart_api_impl.cc +++ b/runtime/vm/dart_api_impl.cc @@ -6441,7 +6441,11 @@ DART_EXPORT void Dart_TimelineEvent(const char* label, if (event != nullptr) { switch (type) { case Dart_Timeline_Event_Begin: - event->Begin(label, timestamp1_or_async_id, timestamp0); + // TODO(derekx): Dart_TimelineEvent() needs to be updated so that arrows + // corresponding to flow events reported by embedders get included in + // Perfetto traces. + event->Begin(label, timestamp1_or_async_id, + /*flow_id=*/TimelineEvent::kNoFlowId, timestamp0); break; case Dart_Timeline_Event_End: event->End(label, timestamp1_or_async_id, timestamp0); diff --git a/runtime/vm/timeline.cc b/runtime/vm/timeline.cc index 300b3465b6d..86c3c721dd7 100644 --- a/runtime/vm/timeline.cc +++ b/runtime/vm/timeline.cc @@ -504,6 +504,7 @@ TIMELINE_STREAM_LIST(TIMELINE_STREAM_DEFINE) TimelineEvent::TimelineEvent() : timestamp0_(0), timestamp1_(0), + flow_id_(TimelineEvent::kNoFlowId), state_(0), label_(nullptr), stream_(nullptr), @@ -581,17 +582,23 @@ void TimelineEvent::Duration(const char* label, set_timestamp1(end_micros); } -void TimelineEvent::Begin(const char* label, int64_t id, int64_t micros) { +void TimelineEvent::Begin(const char* label, + int64_t id, + int64_t flow_id, + int64_t micros) { Init(kBegin, label); set_timestamp0(micros); - // Overload timestamp1_ with the async_id. + // Overload timestamp1_ with the task id. This is required for the MacOS + // recorder to work. set_timestamp1(id); + set_flow_id(flow_id); } void TimelineEvent::End(const char* label, int64_t id, int64_t micros) { Init(kEnd, label); set_timestamp0(micros); - // Overload timestamp1_ with the async_id. + // Overload timestamp1_ with the task id. This is required for the MacOS + // recorder to work. set_timestamp1(id); } @@ -662,6 +669,7 @@ void TimelineEvent::Init(EventType event_type, const char* label) { state_ = 0; timestamp0_ = 0; timestamp1_ = 0; + flow_id_ = TimelineEvent::kNoFlowId; OSThread* os_thread = OSThread::Current(); ASSERT(os_thread != nullptr); thread_ = os_thread->trace_id(); @@ -823,6 +831,10 @@ int64_t TimelineEvent::TimeDuration() const { return timestamp1_ - timestamp0_; } +bool TimelineEvent::HasFlowId() const { + return flow_id_ != TimelineEvent::kNoFlowId; +} + bool TimelineEvent::HasIsolateId() const { return isolate_id_ != ILLEGAL_ISOLATE_ID; } @@ -1061,7 +1073,7 @@ void TimelineBeginEndScope::EmitBegin() { } ASSERT(event != nullptr); // Emit a begin event. - event->Begin(label(), id()); + event->Begin(label(), id(), /*flow_id=*/TimelineEvent::kNoFlowId); event->Complete(); } @@ -1854,6 +1866,13 @@ inline void AddBeginEventFields( AddBeginAndInstantEventCommonFields(track_event, event); track_event->set_type( perfetto::protos::pbzero::TrackEvent::Type::TYPE_SLICE_BEGIN); + if (event.HasFlowId()) { + // TODO(derekx): |TrackEvent|s have a |terminating_flow_ids| field that we + // aren't able to populate right now because we aren't keeping track of + // terminating flow IDs in |TimelineEvent|. I'm not even sure if using that + // field will provide any benefit though. + track_event->add_flow_ids(event.flow_id()); + } } inline void AddInstantEventFields( @@ -2177,6 +2196,7 @@ void TimelineEventBlock::Finish() { void DartTimelineEventHelpers::ReportTaskEvent(TimelineEvent* event, int64_t id, + int64_t flow_id, intptr_t type, char* name, char* args) { @@ -2192,7 +2212,7 @@ void DartTimelineEventHelpers::ReportTaskEvent(TimelineEvent* event, event->AsyncEnd(name, id, start); break; case TimelineEvent::kBegin: - event->Begin(name, id, start); + event->Begin(name, id, flow_id, start); break; case TimelineEvent::kEnd: event->End(name, id, start); diff --git a/runtime/vm/timeline.h b/runtime/vm/timeline.h index c3a9678b05d..bc49be0e04e 100644 --- a/runtime/vm/timeline.h +++ b/runtime/vm/timeline.h @@ -332,6 +332,10 @@ class TimelineEvent { kNumEventTypes, }; + // This value must be kept in sync with the value of _noFlowId in + // sdk/lib/developer/timeline.dart. + static const int64_t kNoFlowId = -1; + TimelineEvent(); ~TimelineEvent(); @@ -367,6 +371,7 @@ class TimelineEvent { void Begin(const char* label, int64_t id, + int64_t flow_id, int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()); void End(const char* label, @@ -434,6 +439,9 @@ class TimelineEvent { int64_t timestamp0() const { return timestamp0_; } int64_t timestamp1() const { return timestamp1_; } + bool HasFlowId() const; + int64_t flow_id() const { return flow_id_; } + bool HasIsolateId() const; bool HasIsolateGroupId() const; char* GetFormattedIsolateId() const; @@ -538,6 +546,11 @@ class TimelineEvent { timestamp1_ = value; } + void set_flow_id(int64_t flow_id) { + ASSERT(flow_id_ == TimelineEvent::kNoFlowId); + flow_id_ = flow_id; + } + bool pre_serialized_args() const { return PreSerializedArgsBit::decode(state_); } @@ -562,6 +575,12 @@ class TimelineEvent { int64_t timestamp0_; int64_t timestamp1_; + // This field is only used by the Perfetto recorders, because Perfetto's trace + // format handles flow events by processing flow IDs attached to + // |TimelineEvent::kBegin| events. Other recorders handle flow events by + // processing events of type TimelineEvent::kFlowBegin|, + // |TimelineEvent::kFlowStep|, and |TimelineEvent::kFlowEnd|. + int64_t flow_id_; TimelineEventArguments arguments_; uword state_; const char* label_; @@ -1190,6 +1209,7 @@ class DartTimelineEventHelpers : public AllStatic { public: static void ReportTaskEvent(TimelineEvent* event, int64_t id, + int64_t flow_id, intptr_t type, char* name, char* args); diff --git a/runtime/vm/timeline_test.cc b/runtime/vm/timeline_test.cc index 521d3955896..f841c63dbd5 100644 --- a/runtime/vm/timeline_test.cc +++ b/runtime/vm/timeline_test.cc @@ -85,7 +85,7 @@ class TimelineTestHelper : public AllStatic { ASSERT(start >= 0); TimelineEvent* event = recorder->StartEvent(); ASSERT(event != nullptr); - event->Begin(label, start); + event->Begin(label, /*id=*/-1, /*flow_id=*/TimelineEvent::kNoFlowId, start); event->Complete(); } diff --git a/sdk/lib/_internal/js_dev_runtime/patch/developer_patch.dart b/sdk/lib/_internal/js_dev_runtime/patch/developer_patch.dart index 73c39c01c78..aebce6046c8 100644 --- a/sdk/lib/_internal/js_dev_runtime/patch/developer_patch.dart +++ b/sdk/lib/_internal/js_dev_runtime/patch/developer_patch.dart @@ -158,7 +158,7 @@ int _getNextTaskId() { @patch void _reportTaskEvent( - int taskId, int type, String name, String argumentsAsJson) { + int taskId, int flowId, int type, String name, String argumentsAsJson) { // TODO. } diff --git a/sdk/lib/_internal/js_runtime/lib/developer_patch.dart b/sdk/lib/_internal/js_runtime/lib/developer_patch.dart index a6d56e19c68..8025e9bdd6e 100644 --- a/sdk/lib/_internal/js_runtime/lib/developer_patch.dart +++ b/sdk/lib/_internal/js_runtime/lib/developer_patch.dart @@ -78,7 +78,7 @@ int _getNextTaskId() { @patch void _reportTaskEvent( - int taskId, int type, String name, String argumentsAsJson) { + int taskId, int flowId, int type, String name, String argumentsAsJson) { // TODO. } diff --git a/sdk/lib/_internal/vm/lib/timeline.dart b/sdk/lib/_internal/vm/lib/timeline.dart index f5452afcc16..1e8a17760c9 100644 --- a/sdk/lib/_internal/vm/lib/timeline.dart +++ b/sdk/lib/_internal/vm/lib/timeline.dart @@ -19,4 +19,4 @@ external int _getNextTaskId(); @patch @pragma("vm:external-name", "Timeline_reportTaskEvent") external void _reportTaskEvent( - int taskId, int type, String name, String argumentsAsJson); + int taskId, int flowId, int type, String name, String argumentsAsJson); diff --git a/sdk/lib/_internal/wasm/lib/developer.dart b/sdk/lib/_internal/wasm/lib/developer.dart index af5db20bc51..a06942308d6 100644 --- a/sdk/lib/_internal/wasm/lib/developer.dart +++ b/sdk/lib/_internal/wasm/lib/developer.dart @@ -56,7 +56,7 @@ int _getNextTaskId() => 0; @patch void _reportTaskEvent( - int taskId, int type, String name, String argumentsAsJson) {} + int taskId, int flowId, int type, String name, String argumentsAsJson) {} @patch abstract final class NativeRuntime { diff --git a/sdk/lib/developer/timeline.dart b/sdk/lib/developer/timeline.dart index a9d0bf307fb..4aa97c6404c 100644 --- a/sdk/lib/developer/timeline.dart +++ b/sdk/lib/developer/timeline.dart @@ -28,6 +28,10 @@ const int _flowBegin = 9; const int _flowStep = 10; const int _flowEnd = 11; +// This value must be kept in sync with the value of TimelineEvent::kNoFlowId in +// runtime/vm/timeline.h. +const int _noFlowId = -1; + /// A class to represent Flow events. /// /// [Flow] objects are used to thread flow events between timeline slices, @@ -154,7 +158,8 @@ abstract final class Timeline { // Instant events don't have an id because they don't need to be paired with // other events. int taskId = 0; - _reportTaskEvent(taskId, _instant, name, _argumentsAsJson(arguments)); + _reportTaskEvent(taskId, /*flowId=*/ _noFlowId, _instant, name, + _argumentsAsJson(arguments)); } /// A utility method to time a synchronous [function]. Internally calls @@ -262,8 +267,8 @@ final class TimelineTask { instantArguments ??= {}; instantArguments[_kFilterKey] = _filterKey; } - _reportTaskEvent( - _taskId, _asyncInstant, name, _argumentsAsJson(instantArguments)); + _reportTaskEvent(_taskId, /*flowId=*/ _noFlowId, _asyncInstant, name, + _argumentsAsJson(instantArguments)); } /// Finish the last synchronous operation that was started. @@ -320,12 +325,14 @@ final class _AsyncBlock { // Emit the start event. void _start(Map arguments) { - _reportTaskEvent(_taskId, _asyncBegin, name, _argumentsAsJson(arguments)); + _reportTaskEvent(_taskId, /*flowId=*/ _noFlowId, _asyncBegin, name, + _argumentsAsJson(arguments)); } // Emit the finish event. void _finish(Map? arguments) { - _reportTaskEvent(_taskId, _asyncEnd, name, _argumentsAsJson(arguments)); + _reportTaskEvent(_taskId, /*flowId=*/ _noFlowId, _asyncEnd, name, + _argumentsAsJson(arguments)); } } @@ -351,18 +358,19 @@ final class _SyncBlock { /// Start this block of time. void _startSync() { - _reportTaskEvent(taskId, _begin, name, _jsonArguments); + _reportTaskEvent( + taskId, flow?.id ?? _noFlowId, _begin, name, _jsonArguments); } /// Finish this block of time. At this point, this block can no longer be /// used. void finish() { // Report event to runtime. - _reportTaskEvent(taskId, _end, name, _jsonArguments); + _reportTaskEvent(taskId, flow?.id ?? _noFlowId, _end, name, _jsonArguments); final Flow? tempFlow = flow; if (tempFlow != null) { - _reportTaskEvent(tempFlow.id, tempFlow._type, "${tempFlow.id}", - _argumentsAsJson(null)); + _reportTaskEvent(tempFlow.id, /*flowId=*/ _noFlowId, tempFlow._type, + "${tempFlow.id}", _argumentsAsJson(null)); } } } @@ -388,4 +396,4 @@ external int _getTraceClock(); /// Reports an event for a task. external void _reportTaskEvent( - int taskId, int type, String name, String argumentsAsJson); + int taskId, int flowId, int type, String name, String argumentsAsJson);