ZeroHertzAdapterMode: do not dead-reckon repeated frame timestamps.
Timestamps are currently dead-reckoned for repeated frames in
zero-hertz mode. This leads to an ever increasing
totalPacketSendDelay metric in chrome://webrtc-internals which is
bad.
Fix this by tracking the origin timestamp of the first delay and
measuring time's progression since then. A unit test was added
which fails with the previous version.
go/rtc-0hz-present
Bug: chromium:1255737
Change-Id: I8627b91424f9bc56305b1dbd6a4c0624b6b3669d
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/242863
Reviewed-by: Erik Språng <sprang@webrtc.org>
Commit-Queue: Markus Handell <handellm@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#35595}
diff --git a/video/frame_cadence_adapter.cc b/video/frame_cadence_adapter.cc
index 1a10484..b8af3f0 100644
--- a/video/frame_cadence_adapter.cc
+++ b/video/frame_cadence_adapter.cc
@@ -132,13 +132,25 @@
};
// The state of a scheduled repeat.
struct ScheduledRepeat {
- ScheduledRepeat(Timestamp scheduled, bool idle)
- : scheduled(scheduled), idle(idle) {}
+ ScheduledRepeat(Timestamp origin,
+ int64_t origin_timestamp_us,
+ int64_t origin_ntp_time_ms)
+ : scheduled(origin),
+ idle(false),
+ origin(origin),
+ origin_timestamp_us(origin_timestamp_us),
+ origin_ntp_time_ms(origin_ntp_time_ms) {}
// The instant when the repeat was scheduled.
Timestamp scheduled;
// True if the repeat was scheduled as an idle repeat (long), false
// otherwise.
bool idle;
+ // The moment we decided to start repeating.
+ Timestamp origin;
+ // The timestamp_us of the frame when we started repeating.
+ int64_t origin_timestamp_us;
+ // The ntp_times_ms of the frame when we started repeating.
+ int64_t origin_ntp_time_ms;
};
// Returns true if all spatial layers can be considered to be converged in
@@ -372,7 +384,7 @@
// refinement frames.
ResetQualityConvergenceInfo();
- // If we're not repeating, or we're repeating with non-idle duration, we will
+ // If we're not repeating, or we're repeating with short duration, we will
// very soon send out a frame and don't need a refresh frame.
if (!scheduled_repeat_.has_value() || !scheduled_repeat_->idle) {
RTC_LOG(LS_INFO) << __func__ << " this " << this
@@ -449,7 +461,14 @@
void ZeroHertzAdapterMode::ScheduleRepeat(int frame_id, bool idle_repeat) {
RTC_DLOG(LS_VERBOSE) << __func__ << " this " << this << " frame_id "
<< frame_id;
- scheduled_repeat_.emplace(clock_->CurrentTime(), idle_repeat);
+ Timestamp now = clock_->CurrentTime();
+ if (!scheduled_repeat_.has_value()) {
+ scheduled_repeat_.emplace(now, queued_frames_.front().timestamp_us(),
+ queued_frames_.front().ntp_time_ms());
+ }
+ scheduled_repeat_->scheduled = now;
+ scheduled_repeat_->idle = idle_repeat;
+
TimeDelta repeat_delay = RepeatDuration(idle_repeat);
queue_->PostDelayedTask(
ToQueuedTask(safety_,
@@ -478,15 +497,20 @@
empty_update_rect.MakeEmptyUpdate();
frame.set_update_rect(empty_update_rect);
- // Adjust timestamps of the frame of the repeat, accounting for the delay in
- // scheduling this method.
+ // Adjust timestamps of the frame of the repeat, accounting for the actual
+ // delay since we started repeating.
+ //
// NOTE: No need to update the RTP timestamp as the VideoStreamEncoder
// overwrites it based on its chosen NTP timestamp source.
- TimeDelta scheduled_delay = RepeatDuration(scheduled_repeat_->idle);
- if (frame.timestamp_us() > 0)
- frame.set_timestamp_us(frame.timestamp_us() + scheduled_delay.us());
- if (frame.ntp_time_ms())
- frame.set_ntp_time_ms(frame.ntp_time_ms() + scheduled_delay.ms());
+ TimeDelta total_delay = clock_->CurrentTime() - scheduled_repeat_->origin;
+ if (frame.timestamp_us() > 0) {
+ frame.set_timestamp_us(scheduled_repeat_->origin_timestamp_us +
+ total_delay.us());
+ }
+ if (frame.ntp_time_ms()) {
+ frame.set_ntp_time_ms(scheduled_repeat_->origin_ntp_time_ms +
+ total_delay.ms());
+ }
SendFrameNow(frame);
// Schedule another repeat.
@@ -495,7 +519,10 @@
// RTC_RUN_ON(&sequence_checker_)
void ZeroHertzAdapterMode::SendFrameNow(const VideoFrame& frame) const {
- RTC_DLOG(LS_VERBOSE) << __func__ << " this " << this;
+ RTC_DLOG(LS_VERBOSE) << __func__ << " this " << this << " timestamp "
+ << frame.timestamp() << " timestamp_us "
+ << frame.timestamp_us() << " ntp_time_ms "
+ << frame.ntp_time_ms();
// TODO(crbug.com/1255737): figure out if frames_scheduled_for_processing
// makes sense to compute in this implementation.
callback_->OnFrame(/*post_time=*/clock_->CurrentTime(),
diff --git a/video/frame_cadence_adapter_unittest.cc b/video/frame_cadence_adapter_unittest.cc
index 7e3b3fd..320019c 100644
--- a/video/frame_cadence_adapter_unittest.cc
+++ b/video/frame_cadence_adapter_unittest.cc
@@ -13,17 +13,20 @@
#include <utility>
#include <vector>
+#include "api/task_queue/default_task_queue_factory.h"
#include "api/task_queue/task_queue_base.h"
#include "api/task_queue/task_queue_factory.h"
#include "api/units/timestamp.h"
#include "api/video/nv12_buffer.h"
#include "api/video/video_frame.h"
+#include "rtc_base/event.h"
#include "rtc_base/rate_statistics.h"
#include "rtc_base/ref_counted_object.h"
#include "rtc_base/task_utils/to_queued_task.h"
#include "rtc_base/time_utils.h"
#include "system_wrappers/include/metrics.h"
#include "system_wrappers/include/ntp_time.h"
+#include "system_wrappers/include/sleep.h"
#include "test/field_trial.h"
#include "test/gmock.h"
#include "test/gtest.h"
@@ -879,5 +882,61 @@
ElementsAre(Pair(60 * 4.0 + 5.0 - 1, 1)));
}
+TEST(FrameCadenceAdapterRealTimeTest, TimestampsDoNotDrift) {
+ // This regression test must be performed in realtime because of limitations
+ // in GlobalSimulatedTimeController.
+ //
+ // We sleep for a long while in OnFrame when a repeat was scheduled which
+ // should reflect in accordingly increased ntp_time_ms() and timestamp_us() in
+ // the repeated frames.
+ auto factory = CreateDefaultTaskQueueFactory();
+ auto queue =
+ factory->CreateTaskQueue("test", TaskQueueFactory::Priority::NORMAL);
+ ZeroHertzFieldTrialEnabler enabler;
+ MockCallback callback;
+ Clock* clock = Clock::GetRealTimeClock();
+ std::unique_ptr<FrameCadenceAdapterInterface> adapter;
+ int frame_counter = 0;
+ int64_t original_ntp_time_ms;
+ int64_t original_timestamp_us;
+ rtc::Event event;
+ queue->PostTask(ToQueuedTask([&] {
+ adapter = CreateAdapter(clock);
+ adapter->Initialize(&callback);
+ adapter->SetZeroHertzModeEnabled(
+ FrameCadenceAdapterInterface::ZeroHertzModeParams{});
+ adapter->OnConstraintsChanged(VideoTrackSourceConstraints{0, 30});
+ auto frame = CreateFrame();
+ original_ntp_time_ms = clock->CurrentNtpInMilliseconds();
+ frame.set_ntp_time_ms(original_ntp_time_ms);
+ original_timestamp_us = clock->CurrentTime().us();
+ frame.set_timestamp_us(original_timestamp_us);
+ constexpr int kSleepMs = rtc::kNumMillisecsPerSec / 2;
+ EXPECT_CALL(callback, OnFrame)
+ .WillRepeatedly(
+ Invoke([&](Timestamp, int, const VideoFrame& incoming_frame) {
+ ++frame_counter;
+ // Avoid the first OnFrame and sleep on the second.
+ if (frame_counter == 2) {
+ SleepMs(kSleepMs);
+ } else if (frame_counter == 3) {
+ EXPECT_GE(incoming_frame.ntp_time_ms(),
+ original_ntp_time_ms + kSleepMs);
+ EXPECT_GE(incoming_frame.timestamp_us(),
+ original_timestamp_us + kSleepMs);
+ event.Set();
+ }
+ }));
+ adapter->OnFrame(frame);
+ }));
+ event.Wait(rtc::Event::kForever);
+ rtc::Event finalized;
+ queue->PostTask(ToQueuedTask([&] {
+ adapter = nullptr;
+ finalized.Set();
+ }));
+ finalized.Wait(rtc::Event::kForever);
+}
+
} // namespace
} // namespace webrtc
