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 {