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}
This commit is contained in:
henrika 2023-10-03 10:35:52 +02:00 committed by WebRTC LUCI CQ
parent 9209b50527
commit 40ed3ff07e

View File

@ -376,18 +376,18 @@ void ZeroHertzAdapterMode::OnFrame(Timestamp post_time,
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 @@ void FrameCadenceAdapterImpl::OnFrame(const VideoFrame& frame) {
// 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",