Reland "[VM/Timeline] Make timestamp1_or_id variables more understandable"
Relanding without changes because the cbuild failure was unrelated.
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.
This is a reland of commit 354e1d22cb1cd4cc6b8f7beb60d690b5351a169d
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 <bkonyi@google.com>
> Commit-Queue: Derek Xu <derekx@google.com>
Change-Id: I28c0c3af9869900cc8bb2b3b416904a231d143e0
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/306301
Reviewed-by: Ben Konyi <bkonyi@google.com>
Commit-Queue: Derek Xu <derekx@google.com>
diff --git a/runtime/include/dart_tools_api.h b/runtime/include/dart_tools_api.h
index aab2fa5..0197f33 100644
--- a/runtime/include/dart_tools_api.h
+++ b/runtime/include/dart_tools_api.h
@@ -359,8 +359,17 @@
* \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_async_id The second timestamp of the event or
- * the async id.
+ * \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 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
@@ -370,7 +379,7 @@
*/
DART_EXPORT void Dart_TimelineEvent(const char* label,
int64_t timestamp0,
- int64_t timestamp1_or_async_id,
+ int64_t timestamp1_or_id,
Dart_Timeline_Event_Type type,
intptr_t argument_count,
const char** argument_names,
@@ -403,9 +412,12 @@
*/
int64_t timestamp0;
- /* For a duration event, this is the end time. For an async event, this is the
- * async id. */
- int64_t timestamp1_or_async_id;
+ /**
+ * 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;
/* 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 7c42f26..bdd37b1 100644
--- a/runtime/vm/dart_api_impl.cc
+++ b/runtime/vm/dart_api_impl.cc
@@ -6419,7 +6419,7 @@
DART_EXPORT void Dart_TimelineEvent(const char* label,
int64_t timestamp0,
- int64_t timestamp1_or_async_id,
+ int64_t timestamp1_or_id,
Dart_Timeline_Event_Type type,
intptr_t argument_count,
const char** argument_names,
@@ -6443,37 +6443,37 @@
// 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, timestamp0);
+ event->Begin(label, timestamp1_or_id, timestamp0);
break;
case Dart_Timeline_Event_End:
- event->End(label, timestamp1_or_async_id, timestamp0);
+ event->End(label, timestamp1_or_id, timestamp0);
break;
case Dart_Timeline_Event_Instant:
event->Instant(label, timestamp0);
break;
case Dart_Timeline_Event_Duration:
- event->Duration(label, timestamp0, timestamp1_or_async_id);
+ event->Duration(label, timestamp0, timestamp1_or_id);
break;
case Dart_Timeline_Event_Async_Begin:
- event->AsyncBegin(label, timestamp1_or_async_id, timestamp0);
+ event->AsyncBegin(label, timestamp1_or_id, timestamp0);
break;
case Dart_Timeline_Event_Async_End:
- event->AsyncEnd(label, timestamp1_or_async_id, timestamp0);
+ event->AsyncEnd(label, timestamp1_or_id, timestamp0);
break;
case Dart_Timeline_Event_Async_Instant:
- event->AsyncInstant(label, timestamp1_or_async_id, timestamp0);
+ event->AsyncInstant(label, timestamp1_or_id, timestamp0);
break;
case Dart_Timeline_Event_Counter:
event->Counter(label, timestamp0);
break;
case Dart_Timeline_Event_Flow_Begin:
- event->FlowBegin(label, timestamp1_or_async_id, timestamp0);
+ event->FlowBegin(label, timestamp0);
break;
case Dart_Timeline_Event_Flow_Step:
- event->FlowStep(label, timestamp1_or_async_id, timestamp0);
+ event->FlowStep(label, timestamp0);
break;
case Dart_Timeline_Event_Flow_End:
- event->FlowEnd(label, timestamp1_or_async_id, timestamp0);
+ event->FlowEnd(label, 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 11ff657..7e53aea 100644
--- a/runtime/vm/dart_api_impl_test.cc
+++ b/runtime/vm/dart_api_impl_test.cc
@@ -10387,25 +10387,45 @@
do {
Dart_TimelineEvent("T1", 0, 1, Dart_Timeline_Event_Begin, 0, nullptr,
nullptr);
- Dart_TimelineEvent("T1", 0, 9, Dart_Timeline_Event_End, 0, nullptr,
+ Dart_TimelineEvent("T1", 10, 1, Dart_Timeline_Event_End, 0, nullptr,
nullptr);
- Dart_TimelineEvent("T2", 0, 1, Dart_Timeline_Event_Instant, 0, nullptr,
+
+ Dart_TimelineEvent("T2", 20, 2, Dart_Timeline_Event_Instant, 0, nullptr,
nullptr);
- Dart_TimelineEvent("T3", 0, 2, Dart_Timeline_Event_Duration, 0, 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,
nullptr);
- Dart_TimelineEvent("T4", 0, 3, Dart_Timeline_Event_Async_Begin, 0, nullptr,
+ Dart_TimelineEvent("T4", 60, 4, Dart_Timeline_Event_Async_End, 0, nullptr,
nullptr);
- Dart_TimelineEvent("T4", 9, 3, Dart_Timeline_Event_Async_End, 0, nullptr,
- nullptr);
- Dart_TimelineEvent("T5", 1, 4, Dart_Timeline_Event_Async_Instant, 0,
+
+ Dart_TimelineEvent("T5", 70, 5, Dart_Timeline_Event_Async_Instant, 0,
nullptr, nullptr);
- Dart_TimelineEvent("T7", 1, 4, Dart_Timeline_Event_Counter, 0, 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,
nullptr);
- Dart_TimelineEvent("T8", 1, 4, Dart_Timeline_Event_Flow_Begin, 0, 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,
nullptr);
- Dart_TimelineEvent("T8", 1, 4, Dart_Timeline_Event_Flow_Step, 0, nullptr,
+
+ Dart_TimelineEvent("T8", 110, 8, Dart_Timeline_Event_Begin, 0, nullptr,
nullptr);
- Dart_TimelineEvent("T8", 1, 4, Dart_Timeline_Event_Flow_End, 0, 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,
nullptr);
} while (true);
}
diff --git a/runtime/vm/timeline.cc b/runtime/vm/timeline.cc
index 1f63bef..419cc59 100644
--- a/runtime/vm/timeline.cc
+++ b/runtime/vm/timeline.cc
@@ -504,7 +504,7 @@
TimelineEvent::TimelineEvent()
: timestamp0_(0),
- timestamp1_(0),
+ timestamp1_or_id_(0),
flow_id_count_(0),
flow_ids_(),
state_(0),
@@ -540,7 +540,7 @@
Init(kAsyncBegin, label);
set_timestamp0(micros);
// Overload timestamp1_ with the async_id.
- set_timestamp1(async_id);
+ set_timestamp1_or_id(async_id);
}
void TimelineEvent::AsyncInstant(const char* label,
@@ -549,7 +549,7 @@
Init(kAsyncInstant, label);
set_timestamp0(micros);
// Overload timestamp1_ with the async_id.
- set_timestamp1(async_id);
+ set_timestamp1_or_id(async_id);
}
void TimelineEvent::AsyncEnd(const char* label,
@@ -558,7 +558,7 @@
Init(kAsyncEnd, label);
set_timestamp0(micros);
// Overload timestamp1_ with the async_id.
- set_timestamp1(async_id);
+ set_timestamp1_or_id(async_id);
}
void TimelineEvent::DurationBegin(const char* label, int64_t micros) {
@@ -566,11 +566,6 @@
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);
@@ -581,7 +576,7 @@
int64_t end_micros) {
Init(kDuration, label);
set_timestamp0(start_micros);
- set_timestamp1(end_micros);
+ set_timestamp1_or_id(end_micros);
}
void TimelineEvent::Begin(const char* label,
@@ -589,17 +584,17 @@
int64_t micros) {
Init(kBegin, label);
set_timestamp0(micros);
- // Overload timestamp1_ with the task id. This is required for the MacOS
+ // Overload timestamp1_ with the event ID. This is required for the MacOS
// recorder to work.
- set_timestamp1(id);
+ set_timestamp1_or_id(id);
}
void TimelineEvent::End(const char* label, int64_t id, int64_t micros) {
Init(kEnd, label);
set_timestamp0(micros);
- // Overload timestamp1_ with the task id. This is required for the MacOS
+ // Overload timestamp1_ with the event ID. This is required for the MacOS
// recorder to work.
- set_timestamp1(id);
+ set_timestamp1_or_id(id);
}
void TimelineEvent::Counter(const char* label, int64_t micros) {
@@ -608,30 +603,21 @@
}
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) {
@@ -668,7 +654,7 @@
ASSERT(label != nullptr);
state_ = 0;
timestamp0_ = 0;
- timestamp1_ = 0;
+ timestamp1_or_id_ = 0;
flow_id_count_ = 0;
flow_ids_.reset();
OSThread* os_thread = OSThread::Current();
@@ -971,18 +957,19 @@
int64_t TimelineEvent::HighTime() const {
if (event_type() == kDuration) {
- return timestamp1_;
+ return timestamp1_or_id_;
} else {
return timestamp0_;
}
}
int64_t TimelineEvent::TimeDuration() const {
- if (timestamp1_ == 0) {
+ ASSERT(event_type() == kDuration);
+ if (timestamp1_or_id_ == 0) {
// This duration is still open, use current time as end.
return OS::GetCurrentMonotonicMicrosForTimeline() - timestamp0_;
}
- return timestamp1_ - timestamp0_;
+ return timestamp1_or_id_ - timestamp0_;
}
bool TimelineEvent::HasIsolateId() const {
@@ -1926,7 +1913,7 @@
return;
}
recorder_event.timestamp0 = event->timestamp0();
- recorder_event.timestamp1_or_async_id = event->timestamp1();
+ recorder_event.timestamp1_or_id = event->timestamp1_or_id();
recorder_event.isolate = event->isolate_id();
recorder_event.isolate_group = event->isolate_group_id();
recorder_event.isolate_data = event->isolate_data();
@@ -2438,13 +2425,13 @@
event->End(name, id, start);
break;
case TimelineEvent::kFlowBegin:
- event->FlowBegin(name, id, start);
+ event->FlowBegin(name, start);
break;
case TimelineEvent::kFlowStep:
- event->FlowStep(name, id, start);
+ event->FlowStep(name, start);
break;
case TimelineEvent::kFlowEnd:
- event->FlowEnd(name, id, start);
+ event->FlowEnd(name, start);
break;
case TimelineEvent::kInstant:
event->Instant(name, start);
diff --git a/runtime/vm/timeline.h b/runtime/vm/timeline.h
index 6650599..10de947 100644
--- a/runtime/vm/timeline.h
+++ b/runtime/vm/timeline.h
@@ -364,7 +364,6 @@
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());
@@ -383,13 +382,10 @@
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,
@@ -422,23 +418,26 @@
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() != kDuration);
- return timestamp1_;
+ ASSERT(event_type() == kBegin || event_type() == kEnd ||
+ event_type() == kAsyncBegin || event_type() == kAsyncEnd ||
+ event_type() == kAsyncInstant);
+ return timestamp1_or_id_;
}
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_;
+ return timestamp1_or_id_;
}
int64_t timestamp0() const { return timestamp0_; }
- int64_t timestamp1() const { return timestamp1_; }
+ int64_t timestamp1_or_id() const { return timestamp1_or_id_; }
void SetFlowIds(intptr_t flow_id_count,
std::unique_ptr<const int64_t[]>& flow_ids) {
@@ -562,9 +561,13 @@
ASSERT(timestamp0_ == 0);
timestamp0_ = value;
}
- void set_timestamp1(int64_t value) {
- ASSERT(timestamp1_ == 0);
- timestamp1_ = 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_pre_serialized_args(bool pre_serialized_args) {
@@ -586,7 +589,10 @@
class OwnsLabelBit : public BitField<uword, bool, kOwnsLabelBit, 1> {};
int64_t timestamp0_;
- int64_t timestamp1_;
+ // 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_;
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
@@ -1291,6 +1297,11 @@
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 1050073..8d768ff 100644
--- a/runtime/vm/timeline_test.cc
+++ b/runtime/vm/timeline_test.cc
@@ -133,7 +133,7 @@
event.DurationBegin("apple");
// Measure the duration.
int64_t current_duration = event.TimeDuration();
- event.DurationEnd();
+ event.SetTimeEnd();
// Verify that duration is larger.
EXPECT_GE(event.TimeDuration(), current_duration);
}
@@ -161,7 +161,7 @@
// Check that dur key is present.
EXPECT_SUBSTRING("\"dur\":", js.ToCString());
}
- event.DurationEnd();
+ event.SetTimeEnd();
}
#if defined(DART_HOST_OS_ANDROID) || defined(DART_HOST_OS_LINUX)
@@ -229,7 +229,7 @@
event.SetNumArguments(2);
event.CopyArgument(0, "arg1", "value1");
event.CopyArgument(1, "arg2", "value2");
- event.DurationEnd();
+ event.SetTimeEnd();
}
TEST_CASE(TimelineEventArgumentsPrintJSON) {
@@ -244,7 +244,7 @@
event.SetNumArguments(2);
event.CopyArgument(0, "arg1", "value1");
event.CopyArgument(1, "arg2", "value2");
- event.DurationEnd();
+ event.SetTimeEnd();
{
// Test printing to JSON.
@@ -303,7 +303,7 @@
EXPECT_EQ(0, override.recorder()->CountFor(TimelineEvent::kDuration));
event->DurationBegin("cabbage");
EXPECT_EQ(0, override.recorder()->CountFor(TimelineEvent::kDuration));
- event->DurationEnd();
+ event->SetTimeEnd();
EXPECT_EQ(0, override.recorder()->CountFor(TimelineEvent::kDuration));
event->Complete();
EXPECT_EQ(1, override.recorder()->CountFor(TimelineEvent::kDuration));
