commit 40ed3ff07e1f370c6452789895c77fe5be58e292
author henrika <henrika@webrtc.org> Tue Oct 03 08:35:52 2023
committer WebRTC LUCI CQ <webrtc-scoped@luci-project-accounts.iam.gserviceaccount.com> Tue Oct 03 12:31:13 2023
tree 46c0379d7f1e23f434ac88504510ef9e2ffc04dd
parent 9209b50527a7472f2a28e776588cf161b56b2c1e

Improved event tracing in FrameCadenceAdapter

This CL is a minor cleanup of the work done earlier in [1].
We now remove the arguments which contained the measured delta times
between two TRACE_EVENT_ASYNC_BEGIN and TRACE_EVENT_ASYNC_END events.
Also, the ID for FrameToQueue1 is now unique which was not the case
previously.

The same information can be obtained from the `slice` table and the
`dur` key.

Also renames the events to OnFrameToEncode (total), OnFrameToQueue and
QueueToEncode to match what it measures better.

[1] https://webrtc-review.googlesource.com/c/src/+/322121

Bug: webrtc:15456
Change-Id: Ibe2d7bb53380710671c2c36012dcd573942bae69
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/322220
Commit-Queue: Henrik Andreassson <henrika@webrtc.org>
Reviewed-by: Markus Handell <handellm@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#40860}

video/frame_cadence_adapter.cc

diff --git a/video/frame_cadence_adapter.cc b/video/frame_cadence_adapter.cc
index 918f19a..6d7de56 100644
--- a/video/frame_cadence_adapter.cc
+++ b/video/frame_cadence_adapter.cc
@@ -376,18 +376,18 @@
   int frame_id = current_frame_id_;
   current_frame_id_++;
   scheduled_repeat_ = absl::nullopt;
-  Timestamp task_post_time = clock_->CurrentTime();
-  TimeDelta time_spent_since_post = task_post_time - post_time;
-  TRACE_EVENT_ASYNC_BEGIN0(TRACE_DISABLED_BY_DEFAULT("webrtc"), "FrameToQueue2",
+  TimeDelta time_spent_since_post = clock_->CurrentTime() - post_time;
+  TRACE_EVENT_ASYNC_BEGIN0(TRACE_DISABLED_BY_DEFAULT("webrtc"), "QueueToEncode",
                            frame_id);
   queue_->PostDelayedHighPrecisionTask(
       SafeTask(safety_.flag(),
-               [this, frame_id, task_post_time] {
+               [this, frame_id, frame] {
                  RTC_DCHECK_RUN_ON(&sequence_checker_);
-                 TRACE_EVENT_ASYNC_END1(
-                     TRACE_DISABLED_BY_DEFAULT("webrtc"), "FrameToQueue2",
-                     frame_id, "delay_us",
-                     (clock_->CurrentTime() - task_post_time).us());
+                 TRACE_EVENT_ASYNC_END0(TRACE_DISABLED_BY_DEFAULT("webrtc"),
+                                        "QueueToEncode", frame_id);
+                 TRACE_EVENT_ASYNC_END0(TRACE_DISABLED_BY_DEFAULT("webrtc"),
+                                        "OnFrameToEncode",
+                                        frame.video_frame_buffer().get());
                  ProcessOnDelayedCadence();
                }),
       std::max(frame_delay_ - time_spent_since_post, TimeDelta::Zero()));
@@ -655,17 +655,17 @@
   // Local time in webrtc time base.
   Timestamp post_time = clock_->CurrentTime();
   frames_scheduled_for_processing_.fetch_add(1, std::memory_order_relaxed);
-  TRACE_EVENT_ASYNC_BEGIN0(TRACE_DISABLED_BY_DEFAULT("webrtc"), "FrameToQueue1",
-                           frame.id());
+  TRACE_EVENT_ASYNC_BEGIN0(TRACE_DISABLED_BY_DEFAULT("webrtc"),
+                           "OnFrameToEncode", frame.video_frame_buffer().get());
+  TRACE_EVENT_ASYNC_BEGIN0(TRACE_DISABLED_BY_DEFAULT("webrtc"),
+                           "OnFrameToQueue", frame.video_frame_buffer().get());
   queue_->PostTask(SafeTask(safety_.flag(), [this, post_time, frame] {
     RTC_DCHECK_RUN_ON(queue_);
-    Timestamp current_time = clock_->CurrentTime();
-    TRACE_EVENT_ASYNC_END1(TRACE_DISABLED_BY_DEFAULT("webrtc"), "FrameToQueue1",
-                           frame.id(), "delay_us",
-                           (current_time - post_time).us());
+    TRACE_EVENT_ASYNC_END0(TRACE_DISABLED_BY_DEFAULT("webrtc"),
+                           "OnFrameToQueue", frame.video_frame_buffer().get());
     if (zero_hertz_adapter_created_timestamp_.has_value()) {
       TimeDelta time_until_first_frame =
-          current_time - *zero_hertz_adapter_created_timestamp_;
+          clock_->CurrentTime() - *zero_hertz_adapter_created_timestamp_;
       zero_hertz_adapter_created_timestamp_ = absl::nullopt;
       RTC_HISTOGRAM_COUNTS_10000(
           "WebRTC.Screenshare.ZeroHz.TimeUntilFirstFrameMs",