From 87b7c1aa6e55b009f843d0a813914d9c7999b52e Mon Sep 17 00:00:00 2001 From: Danil Chapovalov Date: Tue, 28 Jan 2025 10:51:08 +0100 Subject: [PATCH] Reduce warning logging when minimum playout delay exceed maximum There can be error log each frame when maximum playout delay sent with the frame exceed delay derived from the av-sync. In such scenario prefer to limit the playout delay by the one attached to the received frame. Bug: b/390043766 Change-Id: Ia57969df72f7a649e5a9280d5bb29986f5ea14b7 Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/374284 Reviewed-by: Johannes Kron Reviewed-by: Ilya Nikolaevskiy Commit-Queue: Danil Chapovalov Cr-Commit-Position: refs/heads/main@{#43814} --- modules/video_coding/deprecated/receiver.cc | 3 +- .../video_coding/generic_decoder_unittest.cc | 3 +- modules/video_coding/timing/timing.cc | 10 +-- modules/video_coding/timing/timing.h | 4 +- .../video_coding/timing/timing_unittest.cc | 19 +++-- video/video_receive_stream2.cc | 69 +++++++++++++------ video/video_receive_stream2_unittest.cc | 17 ++++- ...video_stream_buffer_controller_unittest.cc | 9 +-- 8 files changed, 83 insertions(+), 51 deletions(-) diff --git a/modules/video_coding/deprecated/receiver.cc b/modules/video_coding/deprecated/receiver.cc index 524b1cbb22..b4f92940ea 100644 --- a/modules/video_coding/deprecated/receiver.cc +++ b/modules/video_coding/deprecated/receiver.cc @@ -92,8 +92,7 @@ VCMEncodedFrame* VCMReceiver::FrameForDecoding(uint16_t max_wait_time_ms, if (std::optional playout_delay = found_frame->EncodedImage().PlayoutDelay()) { - timing_->set_min_playout_delay(playout_delay->min()); - timing_->set_max_playout_delay(playout_delay->max()); + timing_->set_playout_delay(*playout_delay); } // We have a frame - Set timing and render timestamp. diff --git a/modules/video_coding/generic_decoder_unittest.cc b/modules/video_coding/generic_decoder_unittest.cc index dfc09b9da9..14a33223f3 100644 --- a/modules/video_coding/generic_decoder_unittest.cc +++ b/modules/video_coding/generic_decoder_unittest.cc @@ -206,8 +206,7 @@ TEST_F(GenericDecoderTest, IsLowLatencyStreamActivatedByPlayoutDelay) { EncodedFrame encoded_frame; const VideoPlayoutDelay kPlayoutDelay(TimeDelta::Zero(), TimeDelta::Millis(50)); - timing_.set_min_playout_delay(kPlayoutDelay.min()); - timing_.set_max_playout_delay(kPlayoutDelay.max()); + timing_.set_playout_delay(kPlayoutDelay); generic_decoder_.Decode(encoded_frame, clock_->CurrentTime()); time_controller_.AdvanceTime(TimeDelta::Millis(10)); std::optional decoded_frame = user_callback_.PopLastFrame(); diff --git a/modules/video_coding/timing/timing.cc b/modules/video_coding/timing/timing.cc index 1dbf5bb84a..4163df4645 100644 --- a/modules/video_coding/timing/timing.cc +++ b/modules/video_coding/timing/timing.cc @@ -92,12 +92,12 @@ void VCMTiming::set_min_playout_delay(TimeDelta min_playout_delay) { } } -void VCMTiming::set_max_playout_delay(TimeDelta max_playout_delay) { +void VCMTiming::set_playout_delay(const VideoPlayoutDelay& playout_delay) { MutexLock lock(&mutex_); - if (max_playout_delay_ != max_playout_delay) { - CheckDelaysValid(min_playout_delay_, max_playout_delay); - max_playout_delay_ = max_playout_delay; - } + // No need to call `CheckDelaysValid` as the same invariant (min <= max) + // is guaranteed by the `VideoPlayoutDelay` type. + min_playout_delay_ = playout_delay.min(); + max_playout_delay_ = playout_delay.max(); } void VCMTiming::SetJitterDelay(TimeDelta jitter_delay) { diff --git a/modules/video_coding/timing/timing.h b/modules/video_coding/timing/timing.h index 2b2a05e53d..a6054128b1 100644 --- a/modules/video_coding/timing/timing.h +++ b/modules/video_coding/timing/timing.h @@ -73,8 +73,8 @@ class VCMTiming { TimeDelta min_playout_delay() const; void set_min_playout_delay(TimeDelta min_playout_delay); - // Set/get the maximum playout delay from capture to render in ms. - void set_max_playout_delay(TimeDelta max_playout_delay); + // Set the minimum and maximum playout delay from capture to render. + void set_playout_delay(const VideoPlayoutDelay& playout_delay); // Increases or decreases the current delay to get closer to the target delay. // Calculates how long it has been since the previous call to this function, diff --git a/modules/video_coding/timing/timing_unittest.cc b/modules/video_coding/timing/timing_unittest.cc index 8e49426a4c..122829ad4f 100644 --- a/modules/video_coding/timing/timing_unittest.cc +++ b/modules/video_coding/timing/timing_unittest.cc @@ -203,20 +203,19 @@ TEST(VCMTimingTest, UseLowLatencyRenderer) { // Default is false. EXPECT_FALSE(timing.RenderParameters().use_low_latency_rendering); // False if min playout delay > 0. - timing.set_min_playout_delay(TimeDelta::Millis(10)); - timing.set_max_playout_delay(TimeDelta::Millis(20)); + timing.set_playout_delay({TimeDelta::Millis(10), TimeDelta::Millis(20)}); EXPECT_FALSE(timing.RenderParameters().use_low_latency_rendering); // True if min==0, max > 0. - timing.set_min_playout_delay(TimeDelta::Zero()); + timing.set_playout_delay({TimeDelta::Zero(), TimeDelta::Millis(20)}); EXPECT_TRUE(timing.RenderParameters().use_low_latency_rendering); // True if min==max==0. - timing.set_max_playout_delay(TimeDelta::Zero()); + timing.set_playout_delay({TimeDelta::Zero(), TimeDelta::Zero()}); EXPECT_TRUE(timing.RenderParameters().use_low_latency_rendering); // True also for max playout delay==500 ms. - timing.set_max_playout_delay(TimeDelta::Millis(500)); + timing.set_playout_delay({TimeDelta::Zero(), TimeDelta::Millis(500)}); EXPECT_TRUE(timing.RenderParameters().use_low_latency_rendering); // False if max playout delay > 500 ms. - timing.set_max_playout_delay(TimeDelta::Millis(501)); + timing.set_playout_delay({TimeDelta::Zero(), TimeDelta::Millis(501)}); EXPECT_FALSE(timing.RenderParameters().use_low_latency_rendering); EXPECT_THAT(timing.GetTimings(), HasConsistentVideoDelayTimings()); @@ -232,7 +231,7 @@ TEST(VCMTimingTest, MaxWaitingTimeIsZeroForZeroRenderTime) { test::ScopedKeyValueConfig field_trials; VCMTiming timing(&clock, field_trials); timing.Reset(); - timing.set_max_playout_delay(TimeDelta::Zero()); + timing.set_playout_delay({TimeDelta::Zero(), TimeDelta::Zero()}); for (int i = 0; i < 10; ++i) { clock.AdvanceTime(kTimeDelta); Timestamp now = clock.CurrentTime(); @@ -416,9 +415,8 @@ TEST(VCMTimingTest, GetTimings) { TimeDelta render_delay = TimeDelta::Millis(11); timing.set_render_delay(render_delay); TimeDelta min_playout_delay = TimeDelta::Millis(50); - timing.set_min_playout_delay(min_playout_delay); TimeDelta max_playout_delay = TimeDelta::Millis(500); - timing.set_max_playout_delay(max_playout_delay); + timing.set_playout_delay({min_playout_delay, max_playout_delay}); // On complete. timing.IncomingTimestamp(3000, clock.CurrentTime()); @@ -456,8 +454,7 @@ TEST(VCMTimingTest, GetTimingsBeforeAndAfterValidRtpTimestamp) { // Setup. TimeDelta min_playout_delay = TimeDelta::Millis(50); - timing.set_min_playout_delay(min_playout_delay); - timing.set_max_playout_delay(TimeDelta::Millis(500)); + timing.set_playout_delay({min_playout_delay, TimeDelta::Millis(500)}); // On decodable frames before valid rtp timestamp. constexpr int decodeable_frame_cnt = 10; diff --git a/video/video_receive_stream2.cc b/video/video_receive_stream2.cc index 1a63c4cb51..70c82cc72f 100644 --- a/video/video_receive_stream2.cc +++ b/video/video_receive_stream2.cc @@ -1030,37 +1030,62 @@ void VideoReceiveStream2::UpdatePlayoutDelays() const { // Since nullopt < anything, this will return the largest of the minumum // delays, or nullopt if all are nullopt. std::optional minimum_delay = std::max(min_delays); - if (minimum_delay) { - auto num_playout_delays_set = - absl::c_count_if(min_delays, [](auto opt) { return opt.has_value(); }); - if (num_playout_delays_set > 1 && - timing_->min_playout_delay() != minimum_delay) { + if (!minimum_delay.has_value()) { + // `frame_maximum_playout_delay_` and `frame_minimum_delay_value_` are set + // together. Thus absence of the `minimum_delay` implies absene of the + // `frame_minimum_playout_delay_` and thus implies absence of the + // `frame_maximum_playout_delay_`. + RTC_DCHECK(!frame_maximum_playout_delay_.has_value()); + return; + } + + // When maximum delay is smaller than minimum delay, maximum delay takes + // priority. It arrived with the frame, and thus is an explicit request to + // limit the delay. + if (frame_maximum_playout_delay_.has_value() && + minimum_delay > *frame_maximum_playout_delay_) { + minimum_delay = *frame_maximum_playout_delay_; + if (timing_->min_playout_delay() != *minimum_delay) { RTC_LOG(LS_WARNING) - << "Multiple playout delays set. Actual delay value set to " - << *minimum_delay << " frame min delay=" + << "Maximum playout delay " << *frame_maximum_playout_delay_ + << " overrides minimum delay. frame min delay=" << OptionalDelayToLogString(frame_minimum_playout_delay_) << " base min delay=" << OptionalDelayToLogString(base_minimum_playout_delay_) << " sync min delay=" << OptionalDelayToLogString(syncable_minimum_playout_delay_); } - timing_->set_min_playout_delay(*minimum_delay); - if (frame_minimum_playout_delay_ == TimeDelta::Zero() && - frame_maximum_playout_delay_ > TimeDelta::Zero()) { - // TODO(kron): Estimate frame rate from video stream. - constexpr Frequency kFrameRate = Frequency::Hertz(60); - // Convert playout delay in ms to number of frames. - int max_composition_delay_in_frames = - std::lrint(*frame_maximum_playout_delay_ * kFrameRate); - // Subtract frames in buffer. - max_composition_delay_in_frames = - std::max(max_composition_delay_in_frames - buffer_->Size(), 0); - timing_->SetMaxCompositionDelayInFrames(max_composition_delay_in_frames); - } } - if (frame_maximum_playout_delay_) { - timing_->set_max_playout_delay(*frame_maximum_playout_delay_); + auto num_playout_delays_set = + absl::c_count_if(min_delays, [](auto opt) { return opt.has_value(); }); + if (num_playout_delays_set > 1 && + timing_->min_playout_delay() != *minimum_delay) { + RTC_LOG(LS_WARNING) + << "Multiple playout delays set. Actual delay value set to " + << *minimum_delay << " frame min delay=" + << OptionalDelayToLogString(frame_minimum_playout_delay_) + << " base min delay=" + << OptionalDelayToLogString(base_minimum_playout_delay_) + << " sync min delay=" + << OptionalDelayToLogString(syncable_minimum_playout_delay_); + } + if (frame_maximum_playout_delay_.has_value()) { + timing_->set_playout_delay({*minimum_delay, *frame_maximum_playout_delay_}); + } else { + timing_->set_min_playout_delay(*minimum_delay); + } + if (frame_minimum_playout_delay_ == TimeDelta::Zero() && + frame_maximum_playout_delay_ > TimeDelta::Zero()) { + // TODO(kron): Estimate frame rate from video stream. + constexpr Frequency kFrameRate = Frequency::Hertz(60); + // Convert playout delay to number of frames. + int max_composition_delay_in_frames = + std::lrint(*frame_maximum_playout_delay_ * kFrameRate); + // Subtract frames in buffer. + max_composition_delay_in_frames = + std::max(max_composition_delay_in_frames - buffer_->Size(), 0); + timing_->SetMaxCompositionDelayInFrames(max_composition_delay_in_frames); } } diff --git a/video/video_receive_stream2_unittest.cc b/video/video_receive_stream2_unittest.cc index b3a0cded93..03316996d4 100644 --- a/video/video_receive_stream2_unittest.cc +++ b/video/video_receive_stream2_unittest.cc @@ -306,7 +306,7 @@ TEST_P(VideoReceiveStream2Test, CreateFrameFromH264FmtpSpropAndIdr) { TEST_P(VideoReceiveStream2Test, PlayoutDelay) { const VideoPlayoutDelay kPlayoutDelay(TimeDelta::Millis(123), - TimeDelta::Millis(321)); + TimeDelta::Millis(521)); std::unique_ptr test_frame = test::FakeFrameBuilder() .Id(0) @@ -342,6 +342,21 @@ TEST_P(VideoReceiveStream2Test, PlayoutDelay) { EXPECT_EQ(123, timings.min_playout_delay.ms()); } +TEST_P(VideoReceiveStream2Test, MinPlayoutDelayIsLimitedByMaxPlayoutDelay) { + const VideoPlayoutDelay kPlayoutDelay(TimeDelta::Millis(123), + TimeDelta::Millis(321)); + video_receive_stream_->OnCompleteFrame(test::FakeFrameBuilder() + .Id(0) + .PlayoutDelay(kPlayoutDelay) + .AsLast() + .Build()); + EXPECT_EQ(timing_->GetTimings().min_playout_delay, kPlayoutDelay.min()); + + // Check that the biggest minimum delay is limited by the max playout delay. + video_receive_stream_->SetMinimumPlayoutDelay(400); + EXPECT_EQ(timing_->GetTimings().min_playout_delay, kPlayoutDelay.max()); +} + TEST_P(VideoReceiveStream2Test, RenderParametersSetToDefaultValues) { // Default render parameters. const VideoFrame::RenderParameters kDefaultRenderParameters; diff --git a/video/video_stream_buffer_controller_unittest.cc b/video/video_stream_buffer_controller_unittest.cc index c97601b944..d5f0ccd1c1 100644 --- a/video/video_stream_buffer_controller_unittest.cc +++ b/video/video_stream_buffer_controller_unittest.cc @@ -821,8 +821,7 @@ TEST_P(LowLatencyVideoStreamBufferControllerTest, FramesDecodedInstantlyWithLowLatencyRendering) { // Initial keyframe. StartNextDecodeForceKeyframe(); - timing_.set_min_playout_delay(TimeDelta::Zero()); - timing_.set_max_playout_delay(TimeDelta::Millis(10)); + timing_.set_playout_delay({TimeDelta::Zero(), TimeDelta::Millis(10)}); // Playout delay of 0 implies low-latency rendering. auto frame = test::FakeFrameBuilder() .Id(0) @@ -852,8 +851,7 @@ TEST_P(LowLatencyVideoStreamBufferControllerTest, TEST_P(LowLatencyVideoStreamBufferControllerTest, ZeroPlayoutDelayFullQueue) { // Initial keyframe. StartNextDecodeForceKeyframe(); - timing_.set_min_playout_delay(TimeDelta::Zero()); - timing_.set_max_playout_delay(TimeDelta::Millis(10)); + timing_.set_playout_delay({TimeDelta::Zero(), TimeDelta::Millis(10)}); auto frame = test::FakeFrameBuilder() .Id(0) .Time(0) @@ -885,8 +883,7 @@ TEST_P(LowLatencyVideoStreamBufferControllerTest, MinMaxDelayZeroLowLatencyMode) { // Initial keyframe. StartNextDecodeForceKeyframe(); - timing_.set_min_playout_delay(TimeDelta::Zero()); - timing_.set_max_playout_delay(TimeDelta::Zero()); + timing_.set_playout_delay({TimeDelta::Zero(), TimeDelta::Zero()}); // Playout delay of 0 implies low-latency rendering. auto frame = test::FakeFrameBuilder() .Id(0)