From 2e29ed3874cfecf7f506ebc05dbe52d903c3b38d Mon Sep 17 00:00:00 2001 From: Derek Xu Date: Mon, 29 May 2023 19:10:27 +0000 Subject: [PATCH] Revert "[VM/Timeline] Make timestamp1_or_id variables more understandable" This reverts commit 354e1d22cb1cd4cc6b8f7beb60d690b5351a169d. Reason for revert: broke cbuild Original change's description: > [VM/Timeline] Make timestamp1_or_id variables more understandable > > This CL improves documentation, and renames fields/methods to make it > more understandable that timestamp1 and id are stored in the same field > of dart::TimelineEvent (because the event types that need to store > timestamp1 are disjoint from the ones that need to store id). > > TEST=Checked that duration events still looked correct in traces written > by the Perfetto file recorder. Checked that events still looked correct > in traces recorded to the MacOS recorder. > > Change-Id: I25ff1f4c6cc432f035ac2be99fa7f162290ea77f > Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/305880 > Reviewed-by: Ben Konyi > Commit-Queue: Derek Xu Change-Id: I37c74620105299c0b5e7725fd994609af177a9f8 No-Presubmit: true No-Tree-Checks: true No-Try: true Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/306280 Bot-Commit: Rubber Stamper Commit-Queue: Derek Xu --- runtime/include/dart_tools_api.h | 24 ++++------------ runtime/vm/dart_api_impl.cc | 20 ++++++------- runtime/vm/dart_api_impl_test.cc | 42 +++++++-------------------- runtime/vm/timeline.cc | 49 ++++++++++++++++++++------------ runtime/vm/timeline.h | 43 +++++++++++----------------- runtime/vm/timeline_test.cc | 10 +++---- 6 files changed, 79 insertions(+), 109 deletions(-) diff --git a/runtime/include/dart_tools_api.h b/runtime/include/dart_tools_api.h index 0197f332290..aab2fa54075 100644 --- a/runtime/include/dart_tools_api.h +++ b/runtime/include/dart_tools_api.h @@ -359,17 +359,8 @@ typedef enum { * \param label The name of the event. Its lifetime must extend at least until * Dart_Cleanup. * \param timestamp0 The first timestamp of the event. - * \param timestamp1_or_id When reporting an event of type - * |Dart_Timeline_Event_Duration|, the second (end) timestamp of the event - * should be passed through |timestamp1_or_id|. When reporting an event of - * type |Dart_Timeline_Event_Async_Begin|, |Dart_Timeline_Event_Async_End|, - * or |Dart_Timeline_Event_Async_Instant|, the async ID associated with the - * event should be passed through |timestamp1_or_id|. When reporting an - * event of type |Dart_Timeline_Event_Begin| or |Dart_Timeline_Event_End|, - * the event ID associated with the event should be passed through - * |timestamp1_or_id|. Note that this event ID will only be used by the - * MacOS recorder. The argument to |timestamp1_or_id| will not be used when - * reporting events of other types. + * \param timestamp1_or_async_id The second timestamp of the event or + * the async id. * \param argument_count The number of argument names and values. * \param argument_names An array of names of the arguments. The lifetime of the * names must extend at least until Dart_Cleanup. The array may be reclaimed @@ -379,7 +370,7 @@ typedef enum { */ DART_EXPORT void Dart_TimelineEvent(const char* label, int64_t timestamp0, - int64_t timestamp1_or_id, + int64_t timestamp1_or_async_id, Dart_Timeline_Event_Type type, intptr_t argument_count, const char** argument_names, @@ -412,12 +403,9 @@ typedef struct { */ int64_t timestamp0; - /** - * For a duration event, this is the end time. For an async event, this is the - * async ID. For a begin or end event, this is the event ID (which is only - * referenced by the MacOS recorder). - */ - int64_t timestamp1_or_id; + /* For a duration event, this is the end time. For an async event, this is the + * async id. */ + int64_t timestamp1_or_async_id; /* The current isolate of the event, as if by Dart_GetMainPortId, or * ILLEGAL_PORT if the event had no current isolate. */ diff --git a/runtime/vm/dart_api_impl.cc b/runtime/vm/dart_api_impl.cc index bdd37b1eeb3..7c42f262f0a 100644 --- a/runtime/vm/dart_api_impl.cc +++ b/runtime/vm/dart_api_impl.cc @@ -6419,7 +6419,7 @@ DART_EXPORT int64_t Dart_TimelineGetTicksFrequency() { DART_EXPORT void Dart_TimelineEvent(const char* label, int64_t timestamp0, - int64_t timestamp1_or_id, + int64_t timestamp1_or_async_id, Dart_Timeline_Event_Type type, intptr_t argument_count, const char** argument_names, @@ -6443,37 +6443,37 @@ DART_EXPORT void Dart_TimelineEvent(const char* label, // 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_id, timestamp0); + event->Begin(label, timestamp1_or_async_id, timestamp0); break; case Dart_Timeline_Event_End: - event->End(label, timestamp1_or_id, timestamp0); + event->End(label, timestamp1_or_async_id, timestamp0); break; case Dart_Timeline_Event_Instant: event->Instant(label, timestamp0); break; case Dart_Timeline_Event_Duration: - event->Duration(label, timestamp0, timestamp1_or_id); + event->Duration(label, timestamp0, timestamp1_or_async_id); break; case Dart_Timeline_Event_Async_Begin: - event->AsyncBegin(label, timestamp1_or_id, timestamp0); + event->AsyncBegin(label, timestamp1_or_async_id, timestamp0); break; case Dart_Timeline_Event_Async_End: - event->AsyncEnd(label, timestamp1_or_id, timestamp0); + event->AsyncEnd(label, timestamp1_or_async_id, timestamp0); break; case Dart_Timeline_Event_Async_Instant: - event->AsyncInstant(label, timestamp1_or_id, timestamp0); + event->AsyncInstant(label, timestamp1_or_async_id, timestamp0); break; case Dart_Timeline_Event_Counter: event->Counter(label, timestamp0); break; case Dart_Timeline_Event_Flow_Begin: - event->FlowBegin(label, timestamp0); + event->FlowBegin(label, timestamp1_or_async_id, timestamp0); break; case Dart_Timeline_Event_Flow_Step: - event->FlowStep(label, timestamp0); + event->FlowStep(label, timestamp1_or_async_id, timestamp0); break; case Dart_Timeline_Event_Flow_End: - event->FlowEnd(label, timestamp0); + event->FlowEnd(label, timestamp1_or_async_id, timestamp0); break; default: FATAL("Unknown Dart_Timeline_Event_Type"); diff --git a/runtime/vm/dart_api_impl_test.cc b/runtime/vm/dart_api_impl_test.cc index 7e53aea2b25..11ff6572c58 100644 --- a/runtime/vm/dart_api_impl_test.cc +++ b/runtime/vm/dart_api_impl_test.cc @@ -10387,45 +10387,25 @@ static void CreateTimelineEvents(uword param) { do { Dart_TimelineEvent("T1", 0, 1, Dart_Timeline_Event_Begin, 0, nullptr, nullptr); - Dart_TimelineEvent("T1", 10, 1, Dart_Timeline_Event_End, 0, nullptr, + Dart_TimelineEvent("T1", 0, 9, Dart_Timeline_Event_End, 0, nullptr, nullptr); - - Dart_TimelineEvent("T2", 20, 2, Dart_Timeline_Event_Instant, 0, nullptr, + Dart_TimelineEvent("T2", 0, 1, Dart_Timeline_Event_Instant, 0, nullptr, nullptr); - - Dart_TimelineEvent("T3", 30, /*timestamp1=*/40, - Dart_Timeline_Event_Duration, 0, nullptr, nullptr); - - Dart_TimelineEvent("T4", 50, 4, Dart_Timeline_Event_Async_Begin, 0, nullptr, + Dart_TimelineEvent("T3", 0, 2, Dart_Timeline_Event_Duration, 0, nullptr, nullptr); - Dart_TimelineEvent("T4", 60, 4, Dart_Timeline_Event_Async_End, 0, nullptr, + Dart_TimelineEvent("T4", 0, 3, Dart_Timeline_Event_Async_Begin, 0, nullptr, nullptr); - - Dart_TimelineEvent("T5", 70, 5, Dart_Timeline_Event_Async_Instant, 0, + Dart_TimelineEvent("T4", 9, 3, Dart_Timeline_Event_Async_End, 0, nullptr, + nullptr); + Dart_TimelineEvent("T5", 1, 4, Dart_Timeline_Event_Async_Instant, 0, nullptr, nullptr); - - Dart_TimelineEvent("T6", 80, /*timestamp1_or_id=*/-1, - Dart_Timeline_Event_Counter, 0, nullptr, nullptr); - - Dart_TimelineEvent("T7", 90, 7, Dart_Timeline_Event_Begin, 0, nullptr, + Dart_TimelineEvent("T7", 1, 4, Dart_Timeline_Event_Counter, 0, nullptr, nullptr); - Dart_TimelineEvent("F", 90, /*timestamp1_or_id=*/-1, - Dart_Timeline_Event_Flow_Begin, 0, nullptr, nullptr); - Dart_TimelineEvent("T7", 100, 7, Dart_Timeline_Event_End, 0, nullptr, + Dart_TimelineEvent("T8", 1, 4, Dart_Timeline_Event_Flow_Begin, 0, nullptr, nullptr); - - Dart_TimelineEvent("T8", 110, 8, Dart_Timeline_Event_Begin, 0, nullptr, + Dart_TimelineEvent("T8", 1, 4, Dart_Timeline_Event_Flow_Step, 0, nullptr, nullptr); - Dart_TimelineEvent("F", 110, /*timestamp1_or_id=*/-1, - Dart_Timeline_Event_Flow_Step, 0, nullptr, nullptr); - Dart_TimelineEvent("T8", 120, 8, Dart_Timeline_Event_End, 0, nullptr, - nullptr); - - Dart_TimelineEvent("T9", 130, 9, Dart_Timeline_Event_Begin, 0, nullptr, - nullptr); - Dart_TimelineEvent("F", 130, /*timestamp1_or_id=*/-1, - Dart_Timeline_Event_Flow_End, 0, nullptr, nullptr); - Dart_TimelineEvent("T9", 140, 9, Dart_Timeline_Event_End, 0, nullptr, + Dart_TimelineEvent("T8", 1, 4, Dart_Timeline_Event_Flow_End, 0, nullptr, nullptr); } while (true); } diff --git a/runtime/vm/timeline.cc b/runtime/vm/timeline.cc index 419cc593cfb..1f63befd7d4 100644 --- a/runtime/vm/timeline.cc +++ b/runtime/vm/timeline.cc @@ -504,7 +504,7 @@ TIMELINE_STREAM_LIST(TIMELINE_STREAM_DEFINE) TimelineEvent::TimelineEvent() : timestamp0_(0), - timestamp1_or_id_(0), + timestamp1_(0), flow_id_count_(0), flow_ids_(), state_(0), @@ -540,7 +540,7 @@ void TimelineEvent::AsyncBegin(const char* label, Init(kAsyncBegin, label); set_timestamp0(micros); // Overload timestamp1_ with the async_id. - set_timestamp1_or_id(async_id); + set_timestamp1(async_id); } void TimelineEvent::AsyncInstant(const char* label, @@ -549,7 +549,7 @@ void TimelineEvent::AsyncInstant(const char* label, Init(kAsyncInstant, label); set_timestamp0(micros); // Overload timestamp1_ with the async_id. - set_timestamp1_or_id(async_id); + set_timestamp1(async_id); } void TimelineEvent::AsyncEnd(const char* label, @@ -558,7 +558,7 @@ void TimelineEvent::AsyncEnd(const char* label, Init(kAsyncEnd, label); set_timestamp0(micros); // Overload timestamp1_ with the async_id. - set_timestamp1_or_id(async_id); + set_timestamp1(async_id); } void TimelineEvent::DurationBegin(const char* label, int64_t micros) { @@ -566,6 +566,11 @@ void TimelineEvent::DurationBegin(const char* label, int64_t micros) { set_timestamp0(micros); } +void TimelineEvent::DurationEnd(int64_t micros) { + ASSERT(timestamp1_ == 0); + set_timestamp1(micros); +} + void TimelineEvent::Instant(const char* label, int64_t micros) { Init(kInstant, label); set_timestamp0(micros); @@ -576,7 +581,7 @@ void TimelineEvent::Duration(const char* label, int64_t end_micros) { Init(kDuration, label); set_timestamp0(start_micros); - set_timestamp1_or_id(end_micros); + set_timestamp1(end_micros); } void TimelineEvent::Begin(const char* label, @@ -584,17 +589,17 @@ void TimelineEvent::Begin(const char* label, int64_t micros) { Init(kBegin, label); set_timestamp0(micros); - // Overload timestamp1_ with the event ID. This is required for the MacOS + // Overload timestamp1_ with the task id. This is required for the MacOS // recorder to work. - set_timestamp1_or_id(id); + set_timestamp1(id); } void TimelineEvent::End(const char* label, int64_t id, int64_t micros) { Init(kEnd, label); set_timestamp0(micros); - // Overload timestamp1_ with the event ID. This is required for the MacOS + // Overload timestamp1_ with the task id. This is required for the MacOS // recorder to work. - set_timestamp1_or_id(id); + set_timestamp1(id); } void TimelineEvent::Counter(const char* label, int64_t micros) { @@ -603,21 +608,30 @@ void TimelineEvent::Counter(const char* label, int64_t micros) { } void TimelineEvent::FlowBegin(const char* label, + int64_t async_id, int64_t micros) { Init(kFlowBegin, label); set_timestamp0(micros); + // Overload timestamp1_ with the async_id. + set_timestamp1(async_id); } void TimelineEvent::FlowStep(const char* label, + int64_t async_id, int64_t micros) { Init(kFlowStep, label); set_timestamp0(micros); + // Overload timestamp1_ with the async_id. + set_timestamp1(async_id); } void TimelineEvent::FlowEnd(const char* label, + int64_t async_id, int64_t micros) { Init(kFlowEnd, label); set_timestamp0(micros); + // Overload timestamp1_ with the async_id. + set_timestamp1(async_id); } void TimelineEvent::Metadata(const char* label, int64_t micros) { @@ -654,7 +668,7 @@ void TimelineEvent::Init(EventType event_type, const char* label) { ASSERT(label != nullptr); state_ = 0; timestamp0_ = 0; - timestamp1_or_id_ = 0; + timestamp1_ = 0; flow_id_count_ = 0; flow_ids_.reset(); OSThread* os_thread = OSThread::Current(); @@ -957,19 +971,18 @@ int64_t TimelineEvent::LowTime() const { int64_t TimelineEvent::HighTime() const { if (event_type() == kDuration) { - return timestamp1_or_id_; + return timestamp1_; } else { return timestamp0_; } } int64_t TimelineEvent::TimeDuration() const { - ASSERT(event_type() == kDuration); - if (timestamp1_or_id_ == 0) { + if (timestamp1_ == 0) { // This duration is still open, use current time as end. return OS::GetCurrentMonotonicMicrosForTimeline() - timestamp0_; } - return timestamp1_or_id_ - timestamp0_; + return timestamp1_ - timestamp0_; } bool TimelineEvent::HasIsolateId() const { @@ -1913,7 +1926,7 @@ void TimelineEventEmbedderCallbackRecorder::OnEvent(TimelineEvent* event) { return; } recorder_event.timestamp0 = event->timestamp0(); - recorder_event.timestamp1_or_id = event->timestamp1_or_id(); + recorder_event.timestamp1_or_async_id = event->timestamp1(); recorder_event.isolate = event->isolate_id(); recorder_event.isolate_group = event->isolate_group_id(); recorder_event.isolate_data = event->isolate_data(); @@ -2425,13 +2438,13 @@ void DartTimelineEventHelpers::ReportTaskEvent( event->End(name, id, start); break; case TimelineEvent::kFlowBegin: - event->FlowBegin(name, start); + event->FlowBegin(name, id, start); break; case TimelineEvent::kFlowStep: - event->FlowStep(name, start); + event->FlowStep(name, id, start); break; case TimelineEvent::kFlowEnd: - event->FlowEnd(name, start); + event->FlowEnd(name, id, start); break; case TimelineEvent::kInstant: event->Instant(name, start); diff --git a/runtime/vm/timeline.h b/runtime/vm/timeline.h index 10de947038f..665059911fb 100644 --- a/runtime/vm/timeline.h +++ b/runtime/vm/timeline.h @@ -364,6 +364,7 @@ class TimelineEvent { void DurationBegin( const char* label, int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()); + void DurationEnd(int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()); void Instant(const char* label, int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()); @@ -382,10 +383,13 @@ class TimelineEvent { int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()); void FlowBegin(const char* label, + int64_t async_id, int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()); void FlowStep(const char* label, + int64_t async_id, int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()); void FlowEnd(const char* label, + int64_t async_id, int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()); void Metadata(const char* label, @@ -418,26 +422,23 @@ class TimelineEvent { TimelineStream* stream() const { return stream_; } + bool IsFinishedDuration() const { + return (event_type() == kDuration) && (timestamp1_ > timestamp0_); + } + int64_t TimeOrigin() const { return timestamp0_; } int64_t Id() const { - ASSERT(event_type() == kBegin || event_type() == kEnd || - event_type() == kAsyncBegin || event_type() == kAsyncEnd || - event_type() == kAsyncInstant); - return timestamp1_or_id_; + ASSERT(event_type() != kDuration); + return timestamp1_; } int64_t TimeDuration() const; - void SetTimeEnd(int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline()) { - ASSERT(event_type() == kDuration); - ASSERT(timestamp1_or_id_ == 0); - set_timestamp1_or_id(micros); - } int64_t TimeEnd() const { ASSERT(IsFinishedDuration()); - return timestamp1_or_id_; + return timestamp1_; } int64_t timestamp0() const { return timestamp0_; } - int64_t timestamp1_or_id() const { return timestamp1_or_id_; } + int64_t timestamp1() const { return timestamp1_; } void SetFlowIds(intptr_t flow_id_count, std::unique_ptr& flow_ids) { @@ -561,13 +562,9 @@ class TimelineEvent { ASSERT(timestamp0_ == 0); timestamp0_ = value; } - void set_timestamp1_or_id(int64_t value) { - ASSERT(timestamp1_or_id_ == 0); - timestamp1_or_id_ = value; - } - - bool IsFinishedDuration() const { - return (event_type() == kDuration) && (timestamp1_or_id_ > timestamp0_); + void set_timestamp1(int64_t value) { + ASSERT(timestamp1_ == 0); + timestamp1_ = value; } void set_pre_serialized_args(bool pre_serialized_args) { @@ -589,10 +586,7 @@ class TimelineEvent { class OwnsLabelBit : public BitField {}; int64_t timestamp0_; - // For an event of type |kDuration|, this is the end time. For an event of - // type |kBegin| or |kEnd|, this is the event ID (which is only referenced by - // the MacOS recorder). For an async event, this is the async ID. - int64_t timestamp1_or_id_; + int64_t timestamp1_; intptr_t flow_id_count_; // This field is only used by the Perfetto recorders, because Perfetto's trace // format handles flow events by processing flow IDs attached to @@ -1297,11 +1291,6 @@ class TimelineEventPerfettoFileRecorder : public TimelineEventFileRecorderBase { class DartTimelineEventHelpers : public AllStatic { public: - // When reporting an event of type |kAsyncBegin|, |kAsyncEnd|, or - // |kAsyncInstant|, the async ID associated with the event should be passed - // through |id|. When reporting an event of type |kBegin| or |kEnd|, the event - // ID associated with the event should be passed through |id|. Note that this - // event ID will only be used by the MacOS recorder. static void ReportTaskEvent(TimelineEvent* event, int64_t id, intptr_t flow_id_count, diff --git a/runtime/vm/timeline_test.cc b/runtime/vm/timeline_test.cc index 8d768fffdf8..10500735375 100644 --- a/runtime/vm/timeline_test.cc +++ b/runtime/vm/timeline_test.cc @@ -133,7 +133,7 @@ TEST_CASE(TimelineEventDuration) { event.DurationBegin("apple"); // Measure the duration. int64_t current_duration = event.TimeDuration(); - event.SetTimeEnd(); + event.DurationEnd(); // Verify that duration is larger. EXPECT_GE(event.TimeDuration(), current_duration); } @@ -161,7 +161,7 @@ TEST_CASE(TimelineEventDurationPrintJSON) { // Check that dur key is present. EXPECT_SUBSTRING("\"dur\":", js.ToCString()); } - event.SetTimeEnd(); + event.DurationEnd(); } #if defined(DART_HOST_OS_ANDROID) || defined(DART_HOST_OS_LINUX) @@ -229,7 +229,7 @@ TEST_CASE(TimelineEventArguments) { event.SetNumArguments(2); event.CopyArgument(0, "arg1", "value1"); event.CopyArgument(1, "arg2", "value2"); - event.SetTimeEnd(); + event.DurationEnd(); } TEST_CASE(TimelineEventArgumentsPrintJSON) { @@ -244,7 +244,7 @@ TEST_CASE(TimelineEventArgumentsPrintJSON) { event.SetNumArguments(2); event.CopyArgument(0, "arg1", "value1"); event.CopyArgument(1, "arg2", "value2"); - event.SetTimeEnd(); + event.DurationEnd(); { // Test printing to JSON. @@ -303,7 +303,7 @@ TEST_CASE(TimelineEventCallbackRecorderBasic) { EXPECT_EQ(0, override.recorder()->CountFor(TimelineEvent::kDuration)); event->DurationBegin("cabbage"); EXPECT_EQ(0, override.recorder()->CountFor(TimelineEvent::kDuration)); - event->SetTimeEnd(); + event->DurationEnd(); EXPECT_EQ(0, override.recorder()->CountFor(TimelineEvent::kDuration)); event->Complete(); EXPECT_EQ(1, override.recorder()->CountFor(TimelineEvent::kDuration));