[vm] Remove thread time from the VM-internal recorders.

Querying the thread clock takes the overwhelming majority of time when using the VM-internal recorders (ring, startup, endless, file). Including the thread clocks in the timeline allowed visualizing roughly how much an event got scheduled out, but not when. This is a high price to pay for such fuzzy information. Precise scheduling information is available from Fuchsia tracing, systrace or Signposts.

```
import "dart:developer";
main() {
  var n = 1000000;
  var watch = new Stopwatch()..start();
  for (var i = 0; i < n; i++) {
    Timeline.timeSync("EventName", () {});
  }
  print("${watch.elapsedMicroseconds.toDouble() / n} us/event");
}
```

--timeline_recorder=ring      2.751822 -> 0.487936 us/event (5.64x)
--timeline_recorder=systrace  0.440439 -> 0.435997 us/event

TEST=ci
Bug: https://github.com/flutter/flutter/issues/121372
Change-Id: Ib6d625f28384a4e87df2a3305483f0f6facd08ff
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/286661
Commit-Queue: Ryan Macnak <rmacnak@google.com>
Reviewed-by: Ben Konyi <bkonyi@google.com>
Reviewed-by: Siva Annamalai <asiva@google.com>

runtime/vm/os.h

@@ -61,10 +61,6 @@ class OS {
   // If the tracing/timeline configuration on takes timestamps as input, returns
   // the same value as |GetCurrentMonotonicMicros|. Otherwise, returns -1.
   static int64_t GetCurrentMonotonicMicrosForTimeline();
-  // If the tracing/timeline configuration on the current OS supports thread
-  // timestamps, returns the same value as |GetCurrentThreadCPUMicros|.
-  // Otherwise, returns -1.
-  static int64_t GetCurrentThreadCPUMicrosForTimeline();
 
   // Returns the activation frame alignment constraint or one if
   // the platform doesn't care. Guaranteed to be a power of two.

runtime/vm/os_android.cc

@@ -175,15 +175,6 @@ int64_t OS::GetCurrentMonotonicMicrosForTimeline() {
 #endif
 }
 
-int64_t OS::GetCurrentThreadCPUMicrosForTimeline() {
-#if defined(SUPPORT_TIMELINE)
-  if (Timeline::recorder_discards_clock_values()) return -1;
-  return OS::GetCurrentThreadCPUMicros();
-#else
-  return -1;
-#endif
-}
-
 // TODO(5411554):  May need to hoist these architecture dependent code
 // into a architecture specific file e.g: os_ia32_linux.cc
 intptr_t OS::ActivationFrameAlignment() {

runtime/vm/os_fuchsia.cc

@@ -449,13 +449,6 @@ int64_t OS::GetCurrentMonotonicMicrosForTimeline() {
 #endif
 }
 
-// On Fuchsia, thread timestamp values are not used in the tracing/timeline
-// integration. Because of this, we try to avoid querying them, since doing so
-// has both a runtime and trace buffer storage cost.
-int64_t OS::GetCurrentThreadCPUMicrosForTimeline() {
-  return -1;
-}
-
 // TODO(5411554):  May need to hoist these architecture dependent code
 // into a architecture specific file e.g: os_ia32_fuchsia.cc
 intptr_t OS::ActivationFrameAlignment() {

runtime/vm/os_linux.cc

@@ -494,14 +494,6 @@ int64_t OS::GetCurrentMonotonicMicrosForTimeline() {
 #endif
 }
 
-int64_t OS::GetCurrentThreadCPUMicrosForTimeline() {
-#if defined(SUPPORT_TIMELINE)
-  if (Timeline::recorder_discards_clock_values()) return -1;
-  return OS::GetCurrentThreadCPUMicros();
-#else
-  return -1;
-#endif
-}
 // TODO(5411554):  May need to hoist these architecture dependent code
 // into a architecture specific file e.g: os_ia32_linux.cc
 intptr_t OS::ActivationFrameAlignment() {

runtime/vm/os_macos.cc

@@ -121,15 +121,6 @@ int64_t OS::GetCurrentMonotonicMicrosForTimeline() {
 #endif
 }
 
-int64_t OS::GetCurrentThreadCPUMicrosForTimeline() {
-#if defined(SUPPORT_TIMELINE)
-  if (Timeline::recorder_discards_clock_values()) return -1;
-  return OS::GetCurrentThreadCPUMicros();
-#else
-  return -1;
-#endif
-}
-
 intptr_t OS::ActivationFrameAlignment() {
 #if DART_HOST_OS_IOS
 #if TARGET_ARCH_ARM

runtime/vm/os_win.cc

@@ -171,14 +171,6 @@ int64_t OS::GetCurrentMonotonicMicrosForTimeline() {
 #endif
 }
 
-int64_t OS::GetCurrentThreadCPUMicrosForTimeline() {
-#if defined(SUPPORT_TIMELINE)
-  return OS::GetCurrentThreadCPUMicros();
-#else
-  return -1;
-#endif
-}
-
 intptr_t OS::ActivationFrameAlignment() {
 #if defined(TARGET_ARCH_ARM64)
   return 16;

runtime/vm/timeline.cc

@@ -465,8 +465,6 @@ TIMELINE_STREAM_LIST(TIMELINE_STREAM_DEFINE)
 TimelineEvent::TimelineEvent()
     : timestamp0_(0),
       timestamp1_(0),
-      thread_timestamp0_(-1),
-      thread_timestamp1_(-1),
       state_(0),
       label_(NULL),
       stream_(NULL),
@@ -521,18 +519,14 @@ void TimelineEvent::AsyncEnd(const char* label,
   set_timestamp1(async_id);
 }
 
-void TimelineEvent::DurationBegin(const char* label,
-                                  int64_t micros,
-                                  int64_t thread_micros) {
+void TimelineEvent::DurationBegin(const char* label, int64_t micros) {
   Init(kDuration, label);
   set_timestamp0(micros);
-  set_thread_timestamp0(thread_micros);
 }
 
-void TimelineEvent::DurationEnd(int64_t micros, int64_t thread_micros) {
+void TimelineEvent::DurationEnd(int64_t micros) {
   ASSERT(timestamp1_ == 0);
   set_timestamp1(micros);
-  set_thread_timestamp1(thread_micros);
 }
 
 void TimelineEvent::Instant(const char* label, int64_t micros) {
@@ -542,34 +536,22 @@ void TimelineEvent::Instant(const char* label, int64_t micros) {
 
 void TimelineEvent::Duration(const char* label,
                              int64_t start_micros,
-                             int64_t end_micros,
-                             int64_t thread_start_micros,
-                             int64_t thread_end_micros) {
+                             int64_t end_micros) {
   Init(kDuration, label);
   set_timestamp0(start_micros);
   set_timestamp1(end_micros);
-  set_thread_timestamp0(thread_start_micros);
-  set_thread_timestamp1(thread_end_micros);
 }
 
-void TimelineEvent::Begin(const char* label,
-                          int64_t id,
-                          int64_t micros,
-                          int64_t thread_micros) {
+void TimelineEvent::Begin(const char* label, int64_t id, int64_t micros) {
   Init(kBegin, label);
   set_timestamp0(micros);
-  set_thread_timestamp0(thread_micros);
   // Overload timestamp1_ with the async_id.
   set_timestamp1(id);
 }
 
-void TimelineEvent::End(const char* label,
-                        int64_t id,
-                        int64_t micros,
-                        int64_t thread_micros) {
+void TimelineEvent::End(const char* label, int64_t id, int64_t micros) {
   Init(kEnd, label);
   set_timestamp0(micros);
-  set_thread_timestamp0(thread_micros);
   // Overload timestamp1_ with the async_id.
   set_timestamp1(id);
 }
@@ -641,8 +623,6 @@ void TimelineEvent::Init(EventType event_type, const char* label) {
   state_ = 0;
   timestamp0_ = 0;
   timestamp1_ = 0;
-  thread_timestamp0_ = -1;
-  thread_timestamp1_ = -1;
   OSThread* os_thread = OSThread::Current();
   ASSERT(os_thread != NULL);
   thread_ = os_thread->trace_id();
@@ -694,9 +674,6 @@ void TimelineEvent::PrintJSON(JSONWriter* writer) const {
   writer->PrintProperty64("tid", tid);
   writer->PrintProperty64("pid", pid);
   writer->PrintProperty64("ts", TimeOrigin());
-  if (HasThreadCPUTime()) {
-    writer->PrintProperty64("tts", ThreadCPUTimeOrigin());
-  }
   switch (event_type()) {
     case kBegin: {
       writer->PrintProperty("ph", "B");
@@ -707,9 +684,6 @@ void TimelineEvent::PrintJSON(JSONWriter* writer) const {
     case kDuration: {
       writer->PrintProperty("ph", "X");
       writer->PrintProperty64("dur", TimeDuration());
-      if (HasThreadCPUTime()) {
-        writer->PrintProperty64("tdur", ThreadCPUTimeDuration());
-      }
     } break;
     case kInstant: {
       writer->PrintProperty("ph", "i");
@@ -810,24 +784,6 @@ int64_t TimelineEvent::TimeDuration() const {
   return timestamp1_ - timestamp0_;
 }
 
-bool TimelineEvent::HasThreadCPUTime() const {
-  return (thread_timestamp0_ != -1);
-}
-
-int64_t TimelineEvent::ThreadCPUTimeOrigin() const {
-  ASSERT(HasThreadCPUTime());
-  return thread_timestamp0_;
-}
-
-int64_t TimelineEvent::ThreadCPUTimeDuration() const {
-  ASSERT(HasThreadCPUTime());
-  if (thread_timestamp1_ == -1) {
-    // This duration is still open, use current time as end.
-    return OS::GetCurrentThreadCPUMicros() - thread_timestamp0_;
-  }
-  return thread_timestamp1_ - thread_timestamp0_;
-}
-
 bool TimelineEvent::HasIsolateId() const {
   return isolate_id_ != ILLEGAL_ISOLATE_ID;
 }
@@ -1907,7 +1863,6 @@ void DartTimelineEventHelpers::ReportTaskEvent(TimelineEvent* event,
                                                char* name,
                                                char* args) {
   const int64_t start = OS::GetCurrentMonotonicMicrosForTimeline();
-  const int64_t start_cpu = OS::GetCurrentThreadCPUMicrosForTimeline();
   switch (static_cast<TimelineEvent::EventType>(type)) {
     case TimelineEvent::kAsyncInstant:
       event->AsyncInstant(name, id, start);
@@ -1919,10 +1874,10 @@ void DartTimelineEventHelpers::ReportTaskEvent(TimelineEvent* event,
       event->AsyncEnd(name, id, start);
       break;
     case TimelineEvent::kBegin:
-      event->Begin(name, id, start, start_cpu);
+      event->Begin(name, id, start);
       break;
     case TimelineEvent::kEnd:
-      event->End(name, id, start, start_cpu);
+      event->End(name, id, start);
       break;
     case TimelineEvent::kFlowBegin:
       event->FlowBegin(name, id, start);

runtime/vm/timeline.h

@@ -341,31 +341,21 @@ class TimelineEvent {
 
   void DurationBegin(
       const char* label,
-      int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline(),
-      int64_t thread_micros = OS::GetCurrentThreadCPUMicrosForTimeline());
-  void DurationEnd(
-      int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline(),
-      int64_t thread_micros = OS::GetCurrentThreadCPUMicrosForTimeline());
+      int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline());
+  void DurationEnd(int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline());
 
   void Instant(const char* label,
                int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline());
 
-  void Duration(const char* label,
-                int64_t start_micros,
-                int64_t end_micros,
-                int64_t thread_start_micros = -1,
-                int64_t thread_end_micros = -1);
+  void Duration(const char* label, int64_t start_micros, int64_t end_micros);
 
-  void Begin(
-      const char* label,
-      int64_t id,
-      int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline(),
-      int64_t thread_micros = OS::GetCurrentThreadCPUMicrosForTimeline());
+  void Begin(const char* label,
+             int64_t id,
+             int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline());
 
   void End(const char* label,
            int64_t id,
-           int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline(),
-           int64_t thread_micros = OS::GetCurrentThreadCPUMicrosForTimeline());
+           int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline());
 
   void Counter(const char* label,
                int64_t micros = OS::GetCurrentMonotonicMicrosForTimeline());
@@ -414,10 +404,6 @@ class TimelineEvent {
     return (event_type() == kDuration) && (timestamp1_ > timestamp0_);
   }
 
-  bool HasThreadCPUTime() const;
-  int64_t ThreadCPUTimeDuration() const;
-  int64_t ThreadCPUTimeOrigin() const;
-
   int64_t TimeOrigin() const { return timestamp0_; }
   int64_t Id() const {
     ASSERT(event_type() != kDuration);
@@ -536,16 +522,6 @@ class TimelineEvent {
     timestamp1_ = value;
   }
 
-  void set_thread_timestamp0(int64_t value) {
-    ASSERT(thread_timestamp0_ == -1);
-    thread_timestamp0_ = value;
-  }
-
-  void set_thread_timestamp1(int64_t value) {
-    ASSERT(thread_timestamp1_ == -1);
-    thread_timestamp1_ = value;
-  }
-
   bool pre_serialized_args() const {
     return PreSerializedArgsBit::decode(state_);
   }
@@ -570,8 +546,6 @@ class TimelineEvent {
 
   int64_t timestamp0_;
   int64_t timestamp1_;
-  int64_t thread_timestamp0_;
-  int64_t thread_timestamp1_;
   TimelineEventArguments arguments_;
   uword state_;
   const char* label_;

runtime/vm/timeline_test.cc

@@ -205,7 +205,7 @@ TEST_CASE(TimelineEventPrintSystrace) {
 
   // Test a duration event. This event kind is not supported so we should
   // serialize it to an empty string.
-  event.Duration("DUR", 0, 1, 2, 3);
+  event.Duration("DUR", 0, 1);
   TimelineEventSystraceRecorder::PrintSystrace(&event, &buffer[0],
                                                kBufferLength);
   EXPECT_STREQ("", buffer);