Update timestamp extrapolator for all frames that could be decodable.

In FrameBuffer3Proxy, if the stream became undecodable for a long
period of time and during this period the FPS changed,
the render times and decode delays would stray and cause
video pauses. This was because FrameBuffer3Proxy only updated the rtp
timestamp extrapolator on each new decodable temporal unit, rather than
each new frame.

Bug: webrtc:14168
Change-Id: I67a2c9ea392d24f84e82aa04f8c3076de11732af
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/265388
Commit-Queue: Evan Shrubsole <eshr@webrtc.org>
Reviewed-by: Philip Eliasson <philipel@webrtc.org>
Reviewed-by: Erik Språng <sprang@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#37201}
diff --git a/video/frame_buffer_proxy.cc b/video/frame_buffer_proxy.cc
index c701122..601e66e 100644
--- a/video/frame_buffer_proxy.cc
+++ b/video/frame_buffer_proxy.cc
@@ -252,17 +252,18 @@
     RTC_DCHECK_RUN_ON(&worker_sequence_checker_);
     FrameMetadata metadata(*frame);
     int complete_units = buffer_->GetTotalNumberOfContinuousTemporalUnits();
+    size_t size = buffer_->CurrentSize();
     buffer_->InsertFrame(std::move(frame));
-    // Don't update stats or frame timing if the inserted frame did not complete
-    // a new temporal layer.
-    if (complete_units < buffer_->GetTotalNumberOfContinuousTemporalUnits()) {
-      stats_proxy_->OnCompleteFrame(metadata.is_keyframe, metadata.size,
-                                    metadata.contentType);
+    if (size != buffer_->CurrentSize()) {
       RTC_DCHECK(metadata.receive_time) << "Frame receive time must be set!";
       if (!metadata.delayed_by_retransmission && metadata.receive_time)
         timing_->IncomingTimestamp(metadata.rtp_timestamp,
                                    *metadata.receive_time);
-      MaybeScheduleFrameForRelease();
+      if (complete_units < buffer_->GetTotalNumberOfContinuousTemporalUnits()) {
+        stats_proxy_->OnCompleteFrame(metadata.is_keyframe, metadata.size,
+                                      metadata.contentType);
+        MaybeScheduleFrameForRelease();
+      }
     }
 
     return buffer_->LastContinuousFrameId();
diff --git a/video/video_receive_stream2_unittest.cc b/video/video_receive_stream2_unittest.cc
index 3fbc654..5236bb5 100644
--- a/video/video_receive_stream2_unittest.cc
+++ b/video/video_receive_stream2_unittest.cc
@@ -22,11 +22,9 @@
 #include "absl/memory/memory.h"
 #include "absl/types/optional.h"
 #include "api/metronome/test/fake_metronome.h"
-#include "api/task_queue/default_task_queue_factory.h"
 #include "api/test/mock_video_decoder.h"
 #include "api/test/mock_video_decoder_factory.h"
 #include "api/test/time_controller.h"
-#include "api/test/video/function_video_decoder_factory.h"
 #include "api/units/frequency.h"
 #include "api/units/time_delta.h"
 #include "api/video/encoded_image.h"
@@ -38,13 +36,12 @@
 #include "call/rtp_stream_receiver_controller.h"
 #include "call/video_receive_stream.h"
 #include "common_video/test/utilities.h"
-#include "media/base/fake_video_renderer.h"
 #include "media/engine/fake_webrtc_call.h"
 #include "modules/pacing/packet_router.h"
 #include "modules/rtp_rtcp/source/rtp_packet_to_send.h"
 #include "modules/video_coding/encoded_frame.h"
 #include "rtc_base/event.h"
-#include "rtc_base/strings/string_builder.h"
+#include "rtc_base/logging.h"
 #include "system_wrappers/include/clock.h"
 #include "test/fake_decoder.h"
 #include "test/fake_encoded_frame.h"
@@ -52,7 +49,6 @@
 #include "test/gtest.h"
 #include "test/mock_transport.h"
 #include "test/run_loop.h"
-#include "test/scoped_key_value_config.h"
 #include "test/time_controller/simulated_time_controller.h"
 #include "test/video_decoder_proxy_factory.h"
 #include "video/call_stats2.h"
@@ -85,6 +81,7 @@
 using test::video_frame_matchers::Rotation;
 using ::testing::_;
 using ::testing::AllOf;
+using ::testing::AnyNumber;
 using ::testing::ElementsAreArray;
 using ::testing::Eq;
 using ::testing::Field;
@@ -117,18 +114,27 @@
 constexpr uint32_t k30FpsRtpTimestampDelta = kRtpTimestampHz / k30Fps;
 constexpr uint32_t kFirstRtpTimestamp = 90000;
 
-class FakeVideoRenderer : public rtc::VideoSinkInterface<webrtc::VideoFrame> {
+class FakeVideoRenderer : public rtc::VideoSinkInterface<VideoFrame> {
  public:
   explicit FakeVideoRenderer(TimeController* time_controller,
                              test::RunLoop* loop)
       : time_controller_(time_controller), loop_(loop) {}
   ~FakeVideoRenderer() override = default;
 
-  void OnFrame(const webrtc::VideoFrame& frame) override {
+  void OnFrame(const VideoFrame& frame) override {
+    RTC_LOG(LS_VERBOSE) << "Received frame with timestamp="
+                        << frame.timestamp();
+    if (last_frame_) {
+      RTC_LOG(LS_VERBOSE) << "Already had frame queue with timestamp="
+                          << last_frame_->timestamp();
+    }
     last_frame_ = frame;
   }
 
-  absl::optional<webrtc::VideoFrame> WaitForFrame(TimeDelta timeout) {
+  // If `advance_time`, then the clock will always advance by `timeout`.
+  absl::optional<VideoFrame> WaitForFrame(TimeDelta timeout,
+                                          bool advance_time = false) {
+    auto start = time_controller_->GetClock()->CurrentTime();
     if (!last_frame_) {
       loop_->Flush();
       time_controller_->AdvanceTime(TimeDelta::Zero());
@@ -139,13 +145,17 @@
           },
           timeout);
     }
-    absl::optional<webrtc::VideoFrame> ret = std::move(last_frame_);
+    absl::optional<VideoFrame> ret = std::move(last_frame_);
     last_frame_.reset();
+    if (advance_time) {
+      time_controller_->AdvanceTime(
+          timeout - (time_controller_->GetClock()->CurrentTime() - start));
+    }
     return ret;
   }
 
  private:
-  absl::optional<webrtc::VideoFrame> last_frame_;
+  absl::optional<VideoFrame> last_frame_;
   TimeController* const time_controller_;
   test::RunLoop* const loop_;
 };
@@ -154,8 +164,8 @@
   return arg.resolution().width == w && arg.resolution().height == h;
 }
 
-MATCHER_P(Id, id, "") {
-  return arg.id() == id;
+MATCHER_P(RtpTimestamp, timestamp, "") {
+  return arg.timestamp() == timestamp;
 }
 
 // Rtp timestamp for in order frame at 30fps.
@@ -996,15 +1006,112 @@
   video_receive_stream_->Stop();
 }
 
+// If a frame was lost causing the stream to become temporarily non-decodable
+// and the sender reduces their framerate during this time, the video stream
+// should start decoding at the new framerate. However, if the connection is
+// poor, a keyframe will take a long time to send. If the timing of the incoming
+// frames was not kept up to date with the new framerate while the stream was
+// decodable, this late frame will have a large delay as the rtp timestamp of
+// this keyframe will look like the frame arrived early if the frame-rate was
+// not updated.
+TEST_P(VideoReceiveStream2Test, PoorConnectionWithFpsChangeDuringLostFrame) {
+  video_receive_stream_->Start();
+
+  constexpr Frequency k15Fps = Frequency::Hertz(15);
+  constexpr TimeDelta k15FpsDelay = 1 / k15Fps;
+  constexpr uint32_t k15FpsRtpTimestampDelta = kRtpTimestampHz / k15Fps;
+
+  // Initial keyframe and frames at 30fps.
+  video_receive_stream_->OnCompleteFrame(
+      test::FakeFrameBuilder()
+          .Id(0)
+          .PayloadType(99)
+          .Time(RtpTimestampForFrame(0))
+          .ReceivedTime(ReceiveTimeForFrame(0))
+          .AsLast()
+          .Build());
+  EXPECT_THAT(fake_renderer_.WaitForFrame(k30FpsDelay, /*advance_time=*/true),
+              RenderedFrameWith(RtpTimestamp(RtpTimestampForFrame(0))));
+
+  video_receive_stream_->OnCompleteFrame(
+      test::FakeFrameBuilder()
+          .Id(1)
+          .PayloadType(99)
+          .Time(RtpTimestampForFrame(1))
+          .ReceivedTime(ReceiveTimeForFrame(1))
+          .Refs({0})
+          .AsLast()
+          .Build());
+  EXPECT_THAT(fake_renderer_.WaitForFrame(k30FpsDelay, /*advance_time=*/true),
+              RenderedFrameWith(RtpTimestamp(RtpTimestampForFrame(1))));
+
+  // Simulate lost frame 2, followed by 2 second of frames at 30fps, followed by
+  // 2 second of frames at 15 fps, and then a keyframe.
+  time_controller_.AdvanceTime(k30FpsDelay);
+
+  Timestamp send_30fps_end_time = clock_->CurrentTime() + TimeDelta::Seconds(2);
+  int id = 3;
+  EXPECT_CALL(mock_transport_, SendRtcp).Times(AnyNumber());
+  while (clock_->CurrentTime() < send_30fps_end_time) {
+    ++id;
+    video_receive_stream_->OnCompleteFrame(
+        test::FakeFrameBuilder()
+            .Id(id)
+            .PayloadType(99)
+            .Time(RtpTimestampForFrame(id))
+            .ReceivedTime(ReceiveTimeForFrame(id))
+            .Refs({id - 1})
+            .AsLast()
+            .Build());
+    EXPECT_THAT(fake_renderer_.WaitForFrame(k30FpsDelay, /*advance_time=*/true),
+                Eq(absl::nullopt));
+  }
+  uint32_t current_rtp = RtpTimestampForFrame(id);
+  Timestamp send_15fps_end_time = clock_->CurrentTime() + TimeDelta::Seconds(2);
+  while (clock_->CurrentTime() < send_15fps_end_time) {
+    ++id;
+    current_rtp += k15FpsRtpTimestampDelta;
+    video_receive_stream_->OnCompleteFrame(
+        test::FakeFrameBuilder()
+            .Id(id)
+            .PayloadType(99)
+            .Time(current_rtp)
+            .ReceivedTime(clock_->CurrentTime())
+            .Refs({id - 1})
+            .AsLast()
+            .Build());
+    EXPECT_THAT(fake_renderer_.WaitForFrame(k15FpsDelay, /*advance_time=*/true),
+                Eq(absl::nullopt));
+  }
+
+  ++id;
+  current_rtp += k15FpsRtpTimestampDelta;
+  // Insert keyframe which will recover the stream. However, on a poor
+  // connection the keyframe will take significant time to send.
+  constexpr TimeDelta kKeyframeDelay = TimeDelta::Millis(200);
+  video_receive_stream_->OnCompleteFrame(
+      test::FakeFrameBuilder()
+          .Id(id)
+          .PayloadType(99)
+          .Time(current_rtp)
+          .ReceivedTime(clock_->CurrentTime() + kKeyframeDelay)
+          .AsLast()
+          .Build());
+  // If the framerate was not updated to be 15fps from the frames that arrived
+  // previously, this will fail, as the delay will be longer.
+  EXPECT_THAT(fake_renderer_.WaitForFrame(k15FpsDelay, /*advance_time=*/true),
+              RenderedFrameWith(RtpTimestamp(current_rtp)));
+
+  video_receive_stream_->Stop();
+}
+
 INSTANTIATE_TEST_SUITE_P(VideoReceiveStream2Test,
                          VideoReceiveStream2Test,
                          testing::Bool(),
                          [](const auto& test_param_info) {
-                           rtc::StringBuilder ss;
-                           ss << (test_param_info.param
-                                      ? "ScheduleDecodesWithMetronome"
-                                      : "ScheduleDecodesWithPostTask");
-                           return ss.Release();
+                           return (test_param_info.param
+                                       ? "ScheduleDecodesWithMetronome"
+                                       : "ScheduleDecodesWithPostTask");
                          });
 
 }  // namespace webrtc