From bda11ca6da9a420a92cb2d5d22ea28d29dd85251 Mon Sep 17 00:00:00 2001 From: Johannes Kron Date: Fri, 15 Nov 2024 15:54:45 +0100 Subject: [PATCH] Add histogram WebRTC.Video.EstimatedClockDrift_ppm TimestampExtrapolator maps RTP timestamps of received video frames to local timestamps. As part of this mapping, the clock drift between the local and remote clock is estimated. Add the histogram WebRTC.Video.EstimatedClockDrift_ppm to log the relative clock drift in points per million. Bug: b/363166487 Change-Id: I0c2e628ef72c05a93e1f3138c8f71c77467130b7 Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/368342 Reviewed-by: Rasmus Brandt Commit-Queue: Johannes Kron Cr-Commit-Position: refs/heads/main@{#43413} --- modules/video_coding/timing/BUILD.gn | 2 + .../timing/timestamp_extrapolator.cc | 18 ++++- .../timing/timestamp_extrapolator.h | 3 +- .../timing/timestamp_extrapolator_unittest.cc | 80 ++++++++++++++++++- 4 files changed, 96 insertions(+), 7 deletions(-) diff --git a/modules/video_coding/timing/BUILD.gn b/modules/video_coding/timing/BUILD.gn index f6fdc54314..646802be45 100644 --- a/modules/video_coding/timing/BUILD.gn +++ b/modules/video_coding/timing/BUILD.gn @@ -90,6 +90,7 @@ rtc_library("timestamp_extrapolator") { "../../../api/units:timestamp", "../../../modules:module_api_public", "../../../rtc_base:rtc_numerics", + "../../../system_wrappers:metrics", ] } @@ -139,6 +140,7 @@ rtc_library("timing_unittests") { "../../../api/units:timestamp", "../../../rtc_base:histogram_percentile_counter", "../../../rtc_base:timeutils", + "../../../system_wrappers:metrics", "../../../system_wrappers:system_wrappers", "../../../test:scoped_key_value_config", "../../../test:test_support", diff --git a/modules/video_coding/timing/timestamp_extrapolator.cc b/modules/video_coding/timing/timestamp_extrapolator.cc index 15605033c8..c54bbf893f 100644 --- a/modules/video_coding/timing/timestamp_extrapolator.cc +++ b/modules/video_coding/timing/timestamp_extrapolator.cc @@ -14,13 +14,16 @@ #include #include "rtc_base/numerics/sequence_number_unwrapper.h" +#include "system_wrappers/include/metrics.h" namespace webrtc { namespace { +constexpr int kMinimumSamplesToLogEstimatedClockDrift = + 3000; // 100 seconds at 30 fps. constexpr double kLambda = 1; -constexpr uint32_t kStartUpFilterDelayInPackets = 2; +constexpr int kStartUpFilterDelayInPackets = 2; constexpr double kAlarmThreshold = 60e3; // in timestamp ticks, i.e. 15 ms constexpr double kAccDrift = 6600; @@ -38,6 +41,15 @@ TimestampExtrapolator::TimestampExtrapolator(Timestamp start) Reset(start); } +TimestampExtrapolator::~TimestampExtrapolator() { + if (packet_count_ >= kMinimumSamplesToLogEstimatedClockDrift) { + // Relative clock drift per million (ppm). + double clock_drift_ppm = 1e6 * (w_[0] - 90.0) / 90.0; + RTC_HISTOGRAM_COUNTS_100000("WebRTC.Video.EstimatedClockDrift_ppm", + static_cast(std::abs(clock_drift_ppm))); + } +} + void TimestampExtrapolator::Reset(Timestamp start) { start_ = start; prev_ = start_; @@ -117,8 +129,10 @@ void TimestampExtrapolator::Update(Timestamp now, uint32_t ts90khz) { 1 / kLambda * (p_[1][1] - (K[1] * t_ms * p_[0][1] + K[1] * p_[1][1])); p_[0][0] = p00; p_[0][1] = p01; + prev_unwrapped_timestamp_ = unwrapped_ts90khz; - if (packet_count_ < kStartUpFilterDelayInPackets) { + if (packet_count_ < kStartUpFilterDelayInPackets || + packet_count_ < kMinimumSamplesToLogEstimatedClockDrift) { packet_count_++; } } diff --git a/modules/video_coding/timing/timestamp_extrapolator.h b/modules/video_coding/timing/timestamp_extrapolator.h index f3072fa31a..b1cd0b641d 100644 --- a/modules/video_coding/timing/timestamp_extrapolator.h +++ b/modules/video_coding/timing/timestamp_extrapolator.h @@ -24,6 +24,7 @@ namespace webrtc { class TimestampExtrapolator { public: explicit TimestampExtrapolator(Timestamp start); + ~TimestampExtrapolator(); void Update(Timestamp now, uint32_t ts90khz); std::optional ExtrapolateLocalTime(uint32_t timestamp90khz) const; void Reset(Timestamp start); @@ -39,7 +40,7 @@ class TimestampExtrapolator { std::optional first_unwrapped_timestamp_; RtpTimestampUnwrapper unwrapper_; std::optional prev_unwrapped_timestamp_; - uint32_t packet_count_; + int packet_count_; double detector_accumulator_pos_; double detector_accumulator_neg_; }; diff --git a/modules/video_coding/timing/timestamp_extrapolator_unittest.cc b/modules/video_coding/timing/timestamp_extrapolator_unittest.cc index bf0c78ae33..ed8e1345c5 100644 --- a/modules/video_coding/timing/timestamp_extrapolator_unittest.cc +++ b/modules/video_coding/timing/timestamp_extrapolator_unittest.cc @@ -14,11 +14,13 @@ #include #include +#include #include "api/units/frequency.h" #include "api/units/time_delta.h" #include "api/units/timestamp.h" #include "system_wrappers/include/clock.h" +#include "system_wrappers/include/metrics.h" #include "test/gmock.h" #include "test/gtest.h" @@ -154,14 +156,13 @@ TEST(TimestampExtrapolatorTest, Slow90KHzClock) { constexpr TimeDelta k24FpsDelay = 1 / Frequency::Hertz(24); uint32_t rtp = 90000; - ts_extrapolator.Update(clock.CurrentTime(), rtp); // Slow camera will increment RTP at 25 FPS rate even though its producing at // 24 FPS. After 25 frames the extrapolator should settle at this rate. for (int i = 0; i < 25; ++i) { + ts_extrapolator.Update(clock.CurrentTime(), rtp); rtp += kRtpHz / k25Fps; clock.AdvanceTime(k24FpsDelay); - ts_extrapolator.Update(clock.CurrentTime(), rtp); } // The camera would normally produce 25 frames in 90K ticks, but is slow @@ -181,14 +182,13 @@ TEST(TimestampExtrapolatorTest, Fast90KHzClock) { constexpr TimeDelta k26FpsDelay = 1 / Frequency::Hertz(26); uint32_t rtp = 90000; - ts_extrapolator.Update(clock.CurrentTime(), rtp); // Fast camera will increment RTP at 25 FPS rate even though its producing at // 26 FPS. After 25 frames the extrapolator should settle at this rate. for (int i = 0; i < 25; ++i) { + ts_extrapolator.Update(clock.CurrentTime(), rtp); rtp += kRtpHz / k25Fps; clock.AdvanceTime(k26FpsDelay); - ts_extrapolator.Update(clock.CurrentTime(), rtp); } // The camera would normally produce 25 frames in 90K ticks, but is slow @@ -247,4 +247,76 @@ TEST(TimestampExtrapolatorTest, GapInReceivedFrames) { Optional(clock.CurrentTime())); } +TEST(TimestampExtrapolatorTest, EstimatedClockDriftHistogram) { + const std::string kHistogramName = "WebRTC.Video.EstimatedClockDrift_ppm"; + constexpr int kPpmTolerance = 50; + constexpr int kToPpmFactor = 1e6; + constexpr int kMinimumSamples = 3000; + constexpr Frequency k24Fps = Frequency::Hertz(24); + constexpr TimeDelta k24FpsDelay = 1 / k24Fps; + + // This simulates a remote clock without drift with frames produced at 25 fps. + // Local scope to trigger the destructor of TimestampExtrapolator. + { + // Clear all histogram data. + metrics::Reset(); + SimulatedClock clock(Timestamp::Millis(1337)); + TimestampExtrapolator ts_extrapolator(clock.CurrentTime()); + + uint32_t rtp = 90000; + for (int i = 0; i < kMinimumSamples; ++i) { + ts_extrapolator.Update(clock.CurrentTime(), rtp); + rtp += kRtpHz / k25Fps; + clock.AdvanceTime(k25FpsDelay); + } + } + EXPECT_EQ(metrics::NumSamples(kHistogramName), 1); + const int kExpectedIdealClockDriftPpm = 0; + EXPECT_NEAR(kExpectedIdealClockDriftPpm, metrics::MinSample(kHistogramName), + kPpmTolerance); + + // This simulates a slow remote clock, where the RTP timestamps are + // incremented as if the camera was 25 fps even though frames arrive at 24 + // fps. Local scope to trigger the destructor of TimestampExtrapolator. + { + // Clear all histogram data. + metrics::Reset(); + SimulatedClock clock(Timestamp::Millis(1337)); + TimestampExtrapolator ts_extrapolator(clock.CurrentTime()); + + uint32_t rtp = 90000; + for (int i = 0; i < kMinimumSamples; ++i) { + ts_extrapolator.Update(clock.CurrentTime(), rtp); + rtp += kRtpHz / k25Fps; + clock.AdvanceTime(k24FpsDelay); + } + } + EXPECT_EQ(metrics::NumSamples(kHistogramName), 1); + const int kExpectedSlowClockDriftPpm = + std::abs(k24Fps / k25Fps - 1.0) * kToPpmFactor; + EXPECT_NEAR(kExpectedSlowClockDriftPpm, metrics::MinSample(kHistogramName), + kPpmTolerance); + + // This simulates a fast remote clock, where the RTP timestamps are + // incremented as if the camera was 24 fps even though frames arrive at 25 + // fps. Local scope to trigger the destructor of TimestampExtrapolator. + { + // Clear all histogram data. + metrics::Reset(); + SimulatedClock clock(Timestamp::Millis(1337)); + TimestampExtrapolator ts_extrapolator(clock.CurrentTime()); + + uint32_t rtp = 90000; + for (int i = 0; i < kMinimumSamples; ++i) { + ts_extrapolator.Update(clock.CurrentTime(), rtp); + rtp += kRtpHz / k24Fps; + clock.AdvanceTime(k25FpsDelay); + } + } + EXPECT_EQ(metrics::NumSamples(kHistogramName), 1); + const int kExpectedFastClockDriftPpm = (k25Fps / k24Fps - 1.0) * kToPpmFactor; + EXPECT_NEAR(kExpectedFastClockDriftPpm, metrics::MinSample(kHistogramName), + kPpmTolerance); +} + } // namespace webrtc