Cap FrameBuffer3 max wait based on remaining timeout

This was capped to the max wait for a frame, but if the stream was
timing out in a set period of time, it would do this before the frame
was decoded. Instead, this should be done the stream timeout is
triggered.

Bug: webrtc:14168
Change-Id: Iecde082bd223c469f735afeb77a00c0387e47b3b
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/266369
Commit-Queue: Evan Shrubsole <eshr@webrtc.org>
Reviewed-by: Erik Språng <sprang@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#37310}
diff --git a/video/BUILD.gn b/video/BUILD.gn
index 65f02d8..40faf3b 100644
--- a/video/BUILD.gn
+++ b/video/BUILD.gn
@@ -342,6 +342,7 @@
     "../api/task_queue",
     "../api/units:time_delta",
     "../api/units:timestamp",
+    "../rtc_base:logging",
     "../rtc_base/task_utils:repeating_task",
     "../system_wrappers",
   ]
diff --git a/video/frame_buffer_proxy.cc b/video/frame_buffer_proxy.cc
index f69d9da..bc78be0 100644
--- a/video/frame_buffer_proxy.cc
+++ b/video/frame_buffer_proxy.cc
@@ -186,8 +186,6 @@
       std::unique_ptr<FrameDecodeScheduler> frame_decode_scheduler,
       const FieldTrialsView& field_trials)
       : field_trials_(field_trials),
-        max_wait_for_keyframe_(max_wait_for_keyframe),
-        max_wait_for_frame_(max_wait_for_frame),
         clock_(clock),
         worker_queue_(worker_queue),
         decode_queue_(decode_queue),
@@ -393,10 +391,6 @@
     OnFrameReady(std::move(frames), render_time);
   }
 
-  TimeDelta MaxWait() const RTC_RUN_ON(&worker_sequence_checker_) {
-    return keyframe_required_ ? max_wait_for_keyframe_ : max_wait_for_frame_;
-  }
-
   void UpdateDroppedFrames() RTC_RUN_ON(&worker_sequence_checker_) {
     const int dropped_frames = buffer_->GetTotalNumberOfDroppedFrames() -
                                frames_dropped_before_last_new_frame_;
@@ -463,11 +457,15 @@
       return;
     }
 
+    TimeDelta max_wait = timeout_tracker_.TimeUntilTimeout();
+    // Ensures the frame is scheduled for decode before the stream times out.
+    // This is otherwise a race condition.
+    max_wait = std::max(max_wait - TimeDelta::Millis(1), TimeDelta::Zero());
     absl::optional<FrameDecodeTiming::FrameSchedule> schedule;
     while (decodable_tu_info) {
       schedule = decode_timing_.OnFrameBufferUpdated(
           decodable_tu_info->next_rtp_timestamp,
-          decodable_tu_info->last_rtp_timestamp, MaxWait(),
+          decodable_tu_info->last_rtp_timestamp, max_wait,
           IsTooManyFramesQueued());
       if (schedule) {
         // Don't schedule if already waiting for the same frame.
@@ -488,8 +486,6 @@
 
   RTC_NO_UNIQUE_ADDRESS SequenceChecker worker_sequence_checker_;
   const FieldTrialsView& field_trials_;
-  const TimeDelta max_wait_for_keyframe_;
-  const TimeDelta max_wait_for_frame_;
   const absl::optional<RttMultExperiment::Settings> rtt_mult_settings_ =
       RttMultExperiment::GetRttMultValue();
   Clock* const clock_;
diff --git a/video/frame_decode_timing.cc b/video/frame_decode_timing.cc
index 15fcefb..58ecd41 100644
--- a/video/frame_decode_timing.cc
+++ b/video/frame_decode_timing.cc
@@ -30,7 +30,7 @@
                                         uint32_t last_temporal_unit_rtp,
                                         TimeDelta max_wait_for_frame,
                                         bool too_many_frames_queued) {
-  RTC_DCHECK_GT(max_wait_for_frame, TimeDelta::Zero());
+  RTC_DCHECK_GE(max_wait_for_frame, TimeDelta::Zero());
   const Timestamp now = clock_->CurrentTime();
   Timestamp render_time = timing_->RenderTime(next_temporal_unit_rtp, now);
   TimeDelta max_wait =
@@ -42,15 +42,16 @@
   if (max_wait <= -kMaxAllowedFrameDelay &&
       next_temporal_unit_rtp != last_temporal_unit_rtp) {
     RTC_DLOG(LS_VERBOSE) << "Fast-forwarded frame " << next_temporal_unit_rtp
-                         << " render time " << render_time.ms()
-                         << " with delay " << max_wait.ms() << "ms";
+                         << " render time " << render_time << " with delay "
+                         << max_wait;
     return absl::nullopt;
   }
-  RTC_DLOG(LS_VERBOSE) << "Selected frame with rtp " << next_temporal_unit_rtp
-                       << " render time " << render_time.ms()
-                       << " with a max wait of " << max_wait.ms() << "ms";
 
   max_wait.Clamp(TimeDelta::Zero(), max_wait_for_frame);
+  RTC_DLOG(LS_VERBOSE) << "Selected frame with rtp " << next_temporal_unit_rtp
+                       << " render time " << render_time
+                       << " with a max wait of " << max_wait_for_frame
+                       << " clamped to " << max_wait;
   Timestamp latest_decode_time = now + max_wait;
   return FrameSchedule{.latest_decode_time = latest_decode_time,
                        .render_time = render_time};
diff --git a/video/video_receive_stream2_unittest.cc b/video/video_receive_stream2_unittest.cc
index 1846e51..5b25430 100644
--- a/video/video_receive_stream2_unittest.cc
+++ b/video/video_receive_stream2_unittest.cc
@@ -1162,6 +1162,59 @@
   video_receive_stream_->Stop();
 }
 
+TEST_P(VideoReceiveStream2Test, StreamShouldNotTimeoutWhileWaitingForFrame) {
+  // Disable smoothing since this makes it hard to test frame timing.
+  config_.enable_prerenderer_smoothing = false;
+  RecreateReceiveStream();
+
+  video_receive_stream_->Start();
+  EXPECT_CALL(mock_transport_, SendRtcp).Times(AnyNumber());
+
+  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))));
+
+  for (int id = 1; id < 30; ++id) {
+    video_receive_stream_->OnCompleteFrame(
+        test::FakeFrameBuilder()
+            .Id(id)
+            .PayloadType(99)
+            .Time(RtpTimestampForFrame(id))
+            .ReceivedTime(ReceiveTimeForFrame(id))
+            .Refs({0})
+            .AsLast()
+            .Build());
+    EXPECT_THAT(fake_renderer_.WaitForFrame(k30FpsDelay, /*advance_time=*/true),
+                RenderedFrameWith(RtpTimestamp(RtpTimestampForFrame(id))));
+  }
+
+  // Simulate a pause in the stream, followed by a decodable frame that is ready
+  // long in the future. The stream should not timeout in this case, but rather
+  // decode the frame just before the timeout.
+  time_controller_.AdvanceTime(TimeDelta::Millis(2900));
+  uint32_t late_decode_rtp = kFirstRtpTimestamp + 200 * k30FpsRtpTimestampDelta;
+  video_receive_stream_->OnCompleteFrame(
+      test::FakeFrameBuilder()
+          .Id(121)
+          .PayloadType(99)
+          .Time(late_decode_rtp)
+          .ReceivedTime(clock_->CurrentTime())
+          .AsLast()
+          .Build());
+  EXPECT_THAT(fake_renderer_.WaitForFrame(TimeDelta::Millis(100),
+                                          /*advance_time=*/true),
+              RenderedFrameWith(RtpTimestamp(late_decode_rtp)));
+
+  video_receive_stream_->Stop();
+}
+
 INSTANTIATE_TEST_SUITE_P(VideoReceiveStream2Test,
                          VideoReceiveStream2Test,
                          testing::Bool(),
diff --git a/video/video_receive_stream_timeout_tracker.cc b/video/video_receive_stream_timeout_tracker.cc
index c0c8087..32e8bf8 100644
--- a/video/video_receive_stream_timeout_tracker.cc
+++ b/video/video_receive_stream_timeout_tracker.cc
@@ -10,8 +10,11 @@
 
 #include "video/video_receive_stream_timeout_tracker.h"
 
+#include <algorithm>
 #include <utility>
 
+#include "rtc_base/logging.h"
+
 namespace webrtc {
 
 VideoReceiveStreamTimeoutTracker::VideoReceiveStreamTimeoutTracker(
@@ -32,6 +35,10 @@
   return timeout_task_.Running();
 }
 
+TimeDelta VideoReceiveStreamTimeoutTracker::TimeUntilTimeout() const {
+  return std::max(timeout_ - clock_->CurrentTime(), TimeDelta::Zero());
+}
+
 void VideoReceiveStreamTimeoutTracker::Start(bool waiting_for_keyframe) {
   RTC_DCHECK(!timeout_task_.Running());
   waiting_for_keyframe_ = waiting_for_keyframe;
@@ -68,6 +75,7 @@
   // `timeout_` is hit and we have timed out. Schedule the next timeout at
   // the timeout delay.
   if (now >= timeout_) {
+    RTC_DLOG(LS_VERBOSE) << "Stream timeout at " << now;
     TimeDelta timeout_delay = TimeoutForNextFrame();
     timeout_ = now + timeout_delay;
     timeout_cb_(now - last_frame_);
diff --git a/video/video_receive_stream_timeout_tracker.h b/video/video_receive_stream_timeout_tracker.h
index d555ac8..c5a1c73 100644
--- a/video/video_receive_stream_timeout_tracker.h
+++ b/video/video_receive_stream_timeout_tracker.h
@@ -44,6 +44,7 @@
   void Stop();
   void SetWaitingForKeyframe();
   void OnEncodedFrameReleased();
+  TimeDelta TimeUntilTimeout() const;
 
  private:
   TimeDelta TimeoutForNextFrame() const {