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 <brandtr@webrtc.org>
Commit-Queue: Johannes Kron <kron@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#43413}

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",

modules/video_coding/timing/timestamp_extrapolator.cc

@@ -14,13 +14,16 @@
 #include <optional>
 
 #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<int>(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_++;
   }
 }

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<Timestamp> ExtrapolateLocalTime(uint32_t timestamp90khz) const;
   void Reset(Timestamp start);
@@ -39,7 +40,7 @@ class TimestampExtrapolator {
   std::optional<int64_t> first_unwrapped_timestamp_;
   RtpTimestampUnwrapper unwrapper_;
   std::optional<int64_t> prev_unwrapped_timestamp_;
-  uint32_t packet_count_;
+  int packet_count_;
   double detector_accumulator_pos_;
   double detector_accumulator_neg_;
 };

modules/video_coding/timing/timestamp_extrapolator_unittest.cc

@@ -14,11 +14,13 @@
 
 #include <limits>
 #include <optional>
+#include <string>
 
 #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