From bfd343b9bee8fe54ca862da5f66450cf08ca0348 Mon Sep 17 00:00:00 2001 From: Johannes Kron Date: Mon, 1 Jul 2019 10:07:50 +0200 Subject: [PATCH] Add totalDecodeTime to RTCInboundRTPStreamStats MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Pull request to WebRTC stats specification: https://github.com/w3c/webrtc-stats/pull/450 Bug: webrtc:10775 Change-Id: Id032cb324724329fee284ebc84595b9c39208ab8 Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/144035 Commit-Queue: Ilya Nikolaevskiy Reviewed-by: Ilya Nikolaevskiy Reviewed-by: Henrik Boström Reviewed-by: Niels Moller Cr-Commit-Position: refs/heads/master@{#28440} --- api/stats/rtcstats_objects.h | 1 + call/video_receive_stream.h | 2 + media/base/media_channel.h | 2 + media/engine/webrtc_video_engine.cc | 1 + media/engine/webrtc_video_engine_unittest.cc | 2 + modules/video_coding/frame_buffer2.cc | 11 +- .../video_coding/frame_buffer2_unittest.cc | 18 +- modules/video_coding/generic_decoder.cc | 6 +- .../video_coding/generic_decoder_unittest.cc | 1 + .../include/mock/mock_vcm_callbacks.h | 5 +- .../include/video_coding_defines.h | 17 +- modules/video_coding/receiver_unittest.cc | 2 +- modules/video_coding/timing.cc | 14 +- modules/video_coding/timing.h | 7 +- modules/video_coding/timing_unittest.cc | 4 +- pc/rtc_stats_collector.cc | 3 + pc/rtc_stats_collector_unittest.cc | 2 + pc/rtc_stats_integrationtest.cc | 3 + stats/rtcstats_objects.cc | 3 + video/receive_statistics_proxy.cc | 9 +- video/receive_statistics_proxy.h | 4 +- video/receive_statistics_proxy_unittest.cc | 199 ++++++++++-------- video/video_stream_decoder.cc | 4 +- video/video_stream_decoder.h | 1 + video/video_stream_decoder_impl.cc | 3 +- 25 files changed, 186 insertions(+), 138 deletions(-) diff --git a/api/stats/rtcstats_objects.h b/api/stats/rtcstats_objects.h index a178d54a47..1f8b973b2e 100644 --- a/api/stats/rtcstats_objects.h +++ b/api/stats/rtcstats_objects.h @@ -443,6 +443,7 @@ class RTC_EXPORT RTCInboundRTPStreamStats final : public RTCRTPStreamStats { RTCStatsMember gap_discard_rate; RTCStatsMember frames_decoded; RTCStatsMember key_frames_decoded; + RTCStatsMember total_decode_time; // https://henbos.github.io/webrtc-provisional-stats/#dom-rtcinboundrtpstreamstats-contenttype RTCStatsMember content_type; }; diff --git a/call/video_receive_stream.h b/call/video_receive_stream.h index 8bd9982bf4..4bc9b28052 100644 --- a/call/video_receive_stream.h +++ b/call/video_receive_stream.h @@ -85,6 +85,8 @@ class VideoReceiveStream { int render_delay_ms = 10; int64_t interframe_delay_max_ms = -1; uint32_t frames_decoded = 0; + // https://w3c.github.io/webrtc-stats/#dom-rtcinboundrtpstreamstats-totaldecodetime + uint64_t total_decode_time_ms = 0; int64_t first_frame_received_to_decoded_ms = -1; absl::optional qp_sum; diff --git a/media/base/media_channel.h b/media/base/media_channel.h index 8a97022174..80a7e11024 100644 --- a/media/base/media_channel.h +++ b/media/base/media_channel.h @@ -601,6 +601,8 @@ struct VideoReceiverInfo : public MediaReceiverInfo { uint32_t key_frames_decoded = 0; uint32_t frames_rendered = 0; absl::optional qp_sum; + // https://w3c.github.io/webrtc-stats/#dom-rtcinboundrtpstreamstats-totaldecodetime + uint64_t total_decode_time_ms = 0; int64_t interframe_delay_max_ms = -1; uint32_t freeze_count = 0; uint32_t pause_count = 0; diff --git a/media/engine/webrtc_video_engine.cc b/media/engine/webrtc_video_engine.cc index 393fbc5345..4400aef4dc 100644 --- a/media/engine/webrtc_video_engine.cc +++ b/media/engine/webrtc_video_engine.cc @@ -2762,6 +2762,7 @@ WebRtcVideoChannel::WebRtcVideoReceiveStream::GetVideoReceiverInfo( info.key_frames_decoded = stats.frame_counts.key_frames; info.frames_rendered = stats.frames_rendered; info.qp_sum = stats.qp_sum; + info.total_decode_time_ms = stats.total_decode_time_ms; info.last_packet_received_timestamp_ms = stats.rtp_stats.last_packet_received_timestamp_ms; info.first_frame_received_to_decoded_ms = diff --git a/media/engine/webrtc_video_engine_unittest.cc b/media/engine/webrtc_video_engine_unittest.cc index bedda07535..3702064685 100644 --- a/media/engine/webrtc_video_engine_unittest.cc +++ b/media/engine/webrtc_video_engine_unittest.cc @@ -5086,6 +5086,7 @@ TEST_F(WebRtcVideoChannelTest, GetStatsTranslatesDecodeStatsCorrectly) { stats.frames_rendered = 13; stats.frames_decoded = 14; stats.qp_sum = 15; + stats.total_decode_time_ms = 16; stream->SetStats(stats); cricket::VideoMediaInfo info; @@ -5113,6 +5114,7 @@ TEST_F(WebRtcVideoChannelTest, GetStatsTranslatesDecodeStatsCorrectly) { EXPECT_EQ(rtc::checked_cast(stats.frame_counts.key_frames), info.receivers[0].key_frames_decoded); EXPECT_EQ(stats.qp_sum, info.receivers[0].qp_sum); + EXPECT_EQ(stats.total_decode_time_ms, info.receivers[0].total_decode_time_ms); } TEST_F(WebRtcVideoChannelTest, GetStatsTranslatesReceivePacketStatsCorrectly) { diff --git a/modules/video_coding/frame_buffer2.cc b/modules/video_coding/frame_buffer2.cc index d5df3baefa..d9699467a3 100644 --- a/modules/video_coding/frame_buffer2.cc +++ b/modules/video_coding/frame_buffer2.cc @@ -699,19 +699,18 @@ void FrameBuffer::UpdateJitterDelay() { if (!stats_callback_) return; - int decode_ms; int max_decode_ms; int current_delay_ms; int target_delay_ms; int jitter_buffer_ms; int min_playout_delay_ms; int render_delay_ms; - if (timing_->GetTimings(&decode_ms, &max_decode_ms, ¤t_delay_ms, - &target_delay_ms, &jitter_buffer_ms, - &min_playout_delay_ms, &render_delay_ms)) { + if (timing_->GetTimings(&max_decode_ms, ¤t_delay_ms, &target_delay_ms, + &jitter_buffer_ms, &min_playout_delay_ms, + &render_delay_ms)) { stats_callback_->OnFrameBufferTimingsUpdated( - decode_ms, max_decode_ms, current_delay_ms, target_delay_ms, - jitter_buffer_ms, min_playout_delay_ms, render_delay_ms); + max_decode_ms, current_delay_ms, target_delay_ms, jitter_buffer_ms, + min_playout_delay_ms, render_delay_ms); } } diff --git a/modules/video_coding/frame_buffer2_unittest.cc b/modules/video_coding/frame_buffer2_unittest.cc index 083b89b52a..3182579912 100644 --- a/modules/video_coding/frame_buffer2_unittest.cc +++ b/modules/video_coding/frame_buffer2_unittest.cc @@ -59,8 +59,7 @@ class VCMTimingFake : public VCMTiming { return render_time_ms - now_ms - kDecodeTime; } - bool GetTimings(int* decode_ms, - int* max_decode_ms, + bool GetTimings(int* max_decode_ms, int* current_delay_ms, int* target_delay_ms, int* jitter_buffer_ms, @@ -70,16 +69,15 @@ class VCMTimingFake : public VCMTiming { } int GetCurrentJitter() { - int decode_ms; int max_decode_ms; int current_delay_ms; int target_delay_ms; int jitter_buffer_ms; int min_playout_delay_ms; int render_delay_ms; - VCMTiming::GetTimings(&decode_ms, &max_decode_ms, ¤t_delay_ms, - &target_delay_ms, &jitter_buffer_ms, - &min_playout_delay_ms, &render_delay_ms); + VCMTiming::GetTimings(&max_decode_ms, ¤t_delay_ms, &target_delay_ms, + &jitter_buffer_ms, &min_playout_delay_ms, + &render_delay_ms); return jitter_buffer_ms; } @@ -115,9 +113,8 @@ class VCMReceiveStatisticsCallbackMock : public VCMReceiveStatisticsCallback { VideoContentType content_type)); MOCK_METHOD1(OnDiscardedPacketsUpdated, void(int discarded_packets)); MOCK_METHOD1(OnFrameCountsUpdated, void(const FrameCounts& frame_counts)); - MOCK_METHOD7(OnFrameBufferTimingsUpdated, - void(int decode_ms, - int max_decode_ms, + MOCK_METHOD6(OnFrameBufferTimingsUpdated, + void(int max_decode_ms, int current_delay_ms, int target_delay_ms, int jitter_buffer_ms, @@ -548,8 +545,7 @@ TEST_F(TestFrameBuffer2, StatsCallback) { EXPECT_CALL(stats_callback_, OnCompleteFrame(true, kFrameSize, VideoContentType::UNSPECIFIED)); - EXPECT_CALL(stats_callback_, - OnFrameBufferTimingsUpdated(_, _, _, _, _, _, _)); + EXPECT_CALL(stats_callback_, OnFrameBufferTimingsUpdated(_, _, _, _, _, _)); { std::unique_ptr frame(new FrameObjectFake()); diff --git a/modules/video_coding/generic_decoder.cc b/modules/video_coding/generic_decoder.cc index ab83119678..0f928d2bb2 100644 --- a/modules/video_coding/generic_decoder.cc +++ b/modules/video_coding/generic_decoder.cc @@ -91,8 +91,7 @@ void VCMDecodedFrameCallback::Decoded(VideoFrame& decodedImage, if (!decode_time_ms) { decode_time_ms = now_ms - frameInfo->decodeStartTimeMs; } - _timing->StopDecodeTimer(decodedImage.timestamp(), *decode_time_ms, now_ms, - frameInfo->renderTimeMs); + _timing->StopDecodeTimer(*decode_time_ms, now_ms); // Report timing information. TimingFrameInfo timing_frame_info; @@ -147,7 +146,8 @@ void VCMDecodedFrameCallback::Decoded(VideoFrame& decodedImage, decodedImage.set_timestamp_us(frameInfo->renderTimeMs * rtc::kNumMicrosecsPerMillisec); - _receiveCallback->FrameToRender(decodedImage, qp, frameInfo->content_type); + _receiveCallback->FrameToRender(decodedImage, qp, *decode_time_ms, + frameInfo->content_type); } void VCMDecodedFrameCallback::OnDecoderImplementationName( diff --git a/modules/video_coding/generic_decoder_unittest.cc b/modules/video_coding/generic_decoder_unittest.cc index 691561dd54..93d55a67d4 100644 --- a/modules/video_coding/generic_decoder_unittest.cc +++ b/modules/video_coding/generic_decoder_unittest.cc @@ -30,6 +30,7 @@ class ReceiveCallback : public VCMReceiveCallback { public: int32_t FrameToRender(VideoFrame& videoFrame, // NOLINT absl::optional qp, + int32_t decode_time_ms, VideoContentType content_type) override { { rtc::CritScope cs(&lock_); diff --git a/modules/video_coding/include/mock/mock_vcm_callbacks.h b/modules/video_coding/include/mock/mock_vcm_callbacks.h index d2d03789d9..76fc561d63 100644 --- a/modules/video_coding/include/mock/mock_vcm_callbacks.h +++ b/modules/video_coding/include/mock/mock_vcm_callbacks.h @@ -27,8 +27,9 @@ class MockVCMReceiveCallback : public VCMReceiveCallback { MockVCMReceiveCallback() {} virtual ~MockVCMReceiveCallback() {} - MOCK_METHOD3(FrameToRender, - int32_t(VideoFrame&, absl::optional, VideoContentType)); + MOCK_METHOD4( + FrameToRender, + int32_t(VideoFrame&, absl::optional, int32_t, VideoContentType)); MOCK_METHOD1(OnIncomingPayloadType, void(int)); MOCK_METHOD1(OnDecoderImplementationName, void(const char*)); }; diff --git a/modules/video_coding/include/video_coding_defines.h b/modules/video_coding/include/video_coding_defines.h index b7857343a1..043d8c6f29 100644 --- a/modules/video_coding/include/video_coding_defines.h +++ b/modules/video_coding/include/video_coding_defines.h @@ -51,9 +51,21 @@ enum VCMVideoProtection { // rendered. class VCMReceiveCallback { public: + // TODO(kron): Remove once downstream projects are updated. virtual int32_t FrameToRender(VideoFrame& videoFrame, // NOLINT absl::optional qp, - VideoContentType content_type) = 0; + VideoContentType content_type) { + // Cannot be pure virtual since this should be removed from derived + // classes. + return FrameToRender(videoFrame, qp, 0, content_type); + } + + virtual int32_t FrameToRender(VideoFrame& videoFrame, // NOLINT + absl::optional qp, + int32_t decode_time_ms, + VideoContentType content_type) { + return FrameToRender(videoFrame, qp, content_type); + } // Called when the current receive codec changes. virtual void OnIncomingPayloadType(int payload_type); @@ -71,8 +83,7 @@ class VCMReceiveStatisticsCallback { size_t size_bytes, VideoContentType content_type) = 0; - virtual void OnFrameBufferTimingsUpdated(int decode_ms, - int max_decode_ms, + virtual void OnFrameBufferTimingsUpdated(int max_decode_ms, int current_delay_ms, int target_delay_ms, int jitter_buffer_ms, diff --git a/modules/video_coding/receiver_unittest.cc b/modules/video_coding/receiver_unittest.cc index 563116676f..ade26cacbe 100644 --- a/modules/video_coding/receiver_unittest.cc +++ b/modules/video_coding/receiver_unittest.cc @@ -454,7 +454,7 @@ TEST_F(VCMReceiverTimingTest, FrameForDecodingPreferLateDecoding) { int render_delay_ms; int max_decode_ms; int dummy; - timing_.GetTimings(&dummy, &max_decode_ms, &dummy, &dummy, &dummy, &dummy, + timing_.GetTimings(&max_decode_ms, &dummy, &dummy, &dummy, &dummy, &render_delay_ms); // Construct test samples. diff --git a/modules/video_coding/timing.cc b/modules/video_coding/timing.cc index a2a4e473c5..8da2b8588d 100644 --- a/modules/video_coding/timing.cc +++ b/modules/video_coding/timing.cc @@ -28,7 +28,6 @@ VCMTiming::VCMTiming(Clock* clock, VCMTiming* master_timing) max_playout_delay_ms_(10000), jitter_delay_ms_(0), current_delay_ms_(0), - last_decode_ms_(0), prev_frame_timestamp_(0), timing_frame_info_(), num_decoded_frames_(0) { @@ -150,14 +149,17 @@ void VCMTiming::UpdateCurrentDelay(int64_t render_time_ms, } } -void VCMTiming::StopDecodeTimer(uint32_t time_stamp, +void VCMTiming::StopDecodeTimer(uint32_t /*time_stamp*/, int32_t decode_time_ms, int64_t now_ms, - int64_t render_time_ms) { + int64_t /*render_time_ms*/) { + StopDecodeTimer(decode_time_ms, now_ms); +} + +void VCMTiming::StopDecodeTimer(int32_t decode_time_ms, int64_t now_ms) { rtc::CritScope cs(&crit_sect_); codec_timer_->AddTiming(decode_time_ms, now_ms); assert(decode_time_ms >= 0); - last_decode_ms_ = decode_time_ms; ++num_decoded_frames_; } @@ -217,15 +219,13 @@ int VCMTiming::TargetDelayInternal() const { jitter_delay_ms_ + RequiredDecodeTimeMs() + render_delay_ms_); } -bool VCMTiming::GetTimings(int* decode_ms, - int* max_decode_ms, +bool VCMTiming::GetTimings(int* max_decode_ms, int* current_delay_ms, int* target_delay_ms, int* jitter_buffer_ms, int* min_playout_delay_ms, int* render_delay_ms) const { rtc::CritScope cs(&crit_sect_); - *decode_ms = last_decode_ms_; *max_decode_ms = RequiredDecodeTimeMs(); *current_delay_ms = current_delay_ms_; *target_delay_ms = TargetDelayInternal(); diff --git a/modules/video_coding/timing.h b/modules/video_coding/timing.h index c70410eb06..764f0be174 100644 --- a/modules/video_coding/timing.h +++ b/modules/video_coding/timing.h @@ -61,6 +61,9 @@ class VCMTiming { // Stops the decoder timer, should be called when the decoder returns a frame // or when the decoded frame callback is called. + void StopDecodeTimer(int32_t decode_time_ms, int64_t now_ms); + // TODO(kron): Remove once downstream projects has been changed to use the + // above function. void StopDecodeTimer(uint32_t time_stamp, int32_t decode_time_ms, int64_t now_ms, @@ -85,8 +88,7 @@ class VCMTiming { // Return current timing information. Returns true if the first frame has been // decoded, false otherwise. - virtual bool GetTimings(int* decode_ms, - int* max_decode_ms, + virtual bool GetTimings(int* max_decode_ms, int* current_delay_ms, int* target_delay_ms, int* jitter_buffer_ms, @@ -121,7 +123,6 @@ class VCMTiming { int max_playout_delay_ms_ RTC_GUARDED_BY(crit_sect_); int jitter_delay_ms_ RTC_GUARDED_BY(crit_sect_); int current_delay_ms_ RTC_GUARDED_BY(crit_sect_); - int last_decode_ms_ RTC_GUARDED_BY(crit_sect_); uint32_t prev_frame_timestamp_ RTC_GUARDED_BY(crit_sect_); absl::optional timing_frame_info_ RTC_GUARDED_BY(crit_sect_); size_t num_decoded_frames_ RTC_GUARDED_BY(crit_sect_); diff --git a/modules/video_coding/timing_unittest.cc b/modules/video_coding/timing_unittest.cc index b9397ea005..40e8c972b6 100644 --- a/modules/video_coding/timing_unittest.cc +++ b/modules/video_coding/timing_unittest.cc @@ -75,9 +75,7 @@ TEST(ReceiverTiming, Tests) { const uint32_t kDecodeTimeMs = 10; for (int i = 0; i < kFps; i++) { clock.AdvanceTimeMilliseconds(kDecodeTimeMs); - timing.StopDecodeTimer( - timestamp, kDecodeTimeMs, clock.TimeInMilliseconds(), - timing.RenderTimeMs(timestamp, clock.TimeInMilliseconds())); + timing.StopDecodeTimer(kDecodeTimeMs, clock.TimeInMilliseconds()); timestamp += 90000 / kFps; clock.AdvanceTimeMilliseconds(1000 / kFps - kDecodeTimeMs); timing.IncomingTimestamp(timestamp, clock.TimeInMilliseconds()); diff --git a/pc/rtc_stats_collector.cc b/pc/rtc_stats_collector.cc index fb85092221..ec917aec72 100644 --- a/pc/rtc_stats_collector.cc +++ b/pc/rtc_stats_collector.cc @@ -312,6 +312,9 @@ void SetInboundRTPStreamStatsFromVideoReceiverInfo( inbound_video->key_frames_decoded = video_receiver_info.key_frames_decoded; if (video_receiver_info.qp_sum) inbound_video->qp_sum = *video_receiver_info.qp_sum; + inbound_video->total_decode_time = + static_cast(video_receiver_info.total_decode_time_ms) / + rtc::kNumMillisecsPerSec; if (video_receiver_info.last_packet_received_timestamp_ms) { inbound_video->last_packet_received_timestamp = static_cast( diff --git a/pc/rtc_stats_collector_unittest.cc b/pc/rtc_stats_collector_unittest.cc index 2f0e78bba5..963a3bc829 100644 --- a/pc/rtc_stats_collector_unittest.cc +++ b/pc/rtc_stats_collector_unittest.cc @@ -1803,6 +1803,7 @@ TEST_F(RTCStatsCollectorTest, CollectRTCInboundRTPStreamStats_Video) { video_media_info.receivers[0].frames_decoded = 8; video_media_info.receivers[0].key_frames_decoded = 3; video_media_info.receivers[0].qp_sum = absl::nullopt; + video_media_info.receivers[0].total_decode_time_ms = 9000; video_media_info.receivers[0].last_packet_received_timestamp_ms = absl::nullopt; video_media_info.receivers[0].content_type = VideoContentType::UNSPECIFIED; @@ -1840,6 +1841,7 @@ TEST_F(RTCStatsCollectorTest, CollectRTCInboundRTPStreamStats_Video) { expected_video.frames_decoded = 8; expected_video.key_frames_decoded = 3; // |expected_video.qp_sum| should be undefined. + expected_video.total_decode_time = 9.0; // |expected_video.last_packet_received_timestamp| should be undefined. // |expected_video.content_type| should be undefined. diff --git a/pc/rtc_stats_integrationtest.cc b/pc/rtc_stats_integrationtest.cc index 79d6faf152..a05fa0e61a 100644 --- a/pc/rtc_stats_integrationtest.cc +++ b/pc/rtc_stats_integrationtest.cc @@ -805,12 +805,15 @@ class RTCStatsReportVerifier { *inbound_stream.media_type == "video") { verifier.TestMemberIsDefined(inbound_stream.frames_decoded); verifier.TestMemberIsDefined(inbound_stream.key_frames_decoded); + verifier.TestMemberIsNonNegative( + inbound_stream.total_decode_time); // The integration test is not set up to test screen share; don't require // this to be present. verifier.MarkMemberTested(inbound_stream.content_type, true); } else { verifier.TestMemberIsUndefined(inbound_stream.frames_decoded); verifier.TestMemberIsUndefined(inbound_stream.key_frames_decoded); + verifier.TestMemberIsUndefined(inbound_stream.total_decode_time); verifier.TestMemberIsUndefined(inbound_stream.content_type); } return verifier.ExpectAllMembersSuccessfullyTested(); diff --git a/stats/rtcstats_objects.cc b/stats/rtcstats_objects.cc index 2b62990e1d..949e74c4a5 100644 --- a/stats/rtcstats_objects.cc +++ b/stats/rtcstats_objects.cc @@ -615,6 +615,7 @@ WEBRTC_RTCSTATS_IMPL( &gap_discard_rate, &frames_decoded, &key_frames_decoded, + &total_decode_time, &content_type) // clang-format on @@ -645,6 +646,7 @@ RTCInboundRTPStreamStats::RTCInboundRTPStreamStats(std::string&& id, gap_discard_rate("gapDiscardRate"), frames_decoded("framesDecoded"), key_frames_decoded("keyFramesDecoded"), + total_decode_time("totalDecodeTime"), content_type("contentType") {} RTCInboundRTPStreamStats::RTCInboundRTPStreamStats( @@ -670,6 +672,7 @@ RTCInboundRTPStreamStats::RTCInboundRTPStreamStats( gap_discard_rate(other.gap_discard_rate), frames_decoded(other.frames_decoded), key_frames_decoded(other.key_frames_decoded), + total_decode_time(other.total_decode_time), content_type(other.content_type) {} RTCInboundRTPStreamStats::~RTCInboundRTPStreamStats() {} diff --git a/video/receive_statistics_proxy.cc b/video/receive_statistics_proxy.cc index 49ae0d5a1a..6c9d121ac3 100644 --- a/video/receive_statistics_proxy.cc +++ b/video/receive_statistics_proxy.cc @@ -615,7 +615,6 @@ void ReceiveStatisticsProxy::OnDecoderImplementationName( } void ReceiveStatisticsProxy::OnFrameBufferTimingsUpdated( - int decode_ms, int max_decode_ms, int current_delay_ms, int target_delay_ms, @@ -623,14 +622,12 @@ void ReceiveStatisticsProxy::OnFrameBufferTimingsUpdated( int min_playout_delay_ms, int render_delay_ms) { rtc::CritScope lock(&crit_); - stats_.decode_ms = decode_ms; stats_.max_decode_ms = max_decode_ms; stats_.current_delay_ms = current_delay_ms; stats_.target_delay_ms = target_delay_ms; stats_.jitter_buffer_ms = jitter_buffer_ms; stats_.min_playout_delay_ms = min_playout_delay_ms; stats_.render_delay_ms = render_delay_ms; - decode_time_counter_.Add(decode_ms); jitter_buffer_delay_counter_.Add(jitter_buffer_ms); target_delay_counter_.Add(target_delay_ms); current_delay_counter_.Add(current_delay_ms); @@ -723,6 +720,7 @@ void ReceiveStatisticsProxy::DataCountersUpdated( void ReceiveStatisticsProxy::OnDecodedFrame(const VideoFrame& frame, absl::optional qp, + int32_t decode_time_ms, VideoContentType content_type) { rtc::CritScope lock(&crit_); @@ -745,7 +743,6 @@ void ReceiveStatisticsProxy::OnDecodedFrame(const VideoFrame& frame, if (stats_.frames_decoded != 1) { RTC_LOG(LS_WARNING) << "Frames decoded was not 1 when first qp value was received."; - stats_.frames_decoded = 1; } stats_.qp_sum = 0; } @@ -754,8 +751,10 @@ void ReceiveStatisticsProxy::OnDecodedFrame(const VideoFrame& frame, } else if (stats_.qp_sum) { RTC_LOG(LS_WARNING) << "QP sum was already set and no QP was given for a frame."; - stats_.qp_sum = absl::nullopt; } + decode_time_counter_.Add(decode_time_ms); + stats_.decode_ms = decode_time_ms; + stats_.total_decode_time_ms += decode_time_ms; last_content_type_ = content_type; decode_fps_estimator_.Update(1, now_ms); if (last_decoded_frame_time_ms_) { diff --git a/video/receive_statistics_proxy.h b/video/receive_statistics_proxy.h index 6eb9d48562..8aa8f5ea00 100644 --- a/video/receive_statistics_proxy.h +++ b/video/receive_statistics_proxy.h @@ -51,6 +51,7 @@ class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback, void OnDecodedFrame(const VideoFrame& frame, absl::optional qp, + int32_t decode_time_ms, VideoContentType content_type); void OnSyncOffsetUpdated(int64_t sync_offset_ms, double estimated_freq_khz); void OnRenderedFrame(const VideoFrame& frame); @@ -68,8 +69,7 @@ class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback, void OnCompleteFrame(bool is_keyframe, size_t size_bytes, VideoContentType content_type) override; - void OnFrameBufferTimingsUpdated(int decode_ms, - int max_decode_ms, + void OnFrameBufferTimingsUpdated(int max_decode_ms, int current_delay_ms, int target_delay_ms, int jitter_buffer_ms, diff --git a/video/receive_statistics_proxy_unittest.cc b/video/receive_statistics_proxy_unittest.cc index b8293aa7c7..dbd6ccf3e6 100644 --- a/video/receive_statistics_proxy_unittest.cc +++ b/video/receive_statistics_proxy_unittest.cc @@ -88,7 +88,7 @@ TEST_F(ReceiveStatisticsProxyTest, OnDecodedFrameIncreasesFramesDecoded) { EXPECT_EQ(0u, statistics_proxy_->GetStats().frames_decoded); webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (uint32_t i = 1; i <= 3; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); EXPECT_EQ(i, statistics_proxy_->GetStats().frames_decoded); } @@ -99,7 +99,7 @@ TEST_F(ReceiveStatisticsProxyTest, DecodedFpsIsReported) { const int kRequiredSamples = metrics::kMinRunTimeInSeconds * kFps; webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (int i = 0; i < kRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); fake_clock_.AdvanceTimeMilliseconds(1000 / kFps); } @@ -113,7 +113,7 @@ TEST_F(ReceiveStatisticsProxyTest, DecodedFpsIsNotReportedForTooFewSamples) { const int kRequiredSamples = metrics::kMinRunTimeInSeconds * kFps; webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (int i = 0; i < kRequiredSamples - 1; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); fake_clock_.AdvanceTimeMilliseconds(1000 / kFps); } @@ -121,58 +121,67 @@ TEST_F(ReceiveStatisticsProxyTest, DecodedFpsIsNotReportedForTooFewSamples) { EXPECT_EQ(0, metrics::NumSamples("WebRTC.Video.DecodedFramesPerSecond")); } -TEST_F(ReceiveStatisticsProxyTest, DecodedFpsIsReportedWithQpReset) { - const int kFps1 = 10; - webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); - for (int i = 0; i < metrics::kMinRunTimeInSeconds * kFps1; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, - VideoContentType::UNSPECIFIED); - fake_clock_.AdvanceTimeMilliseconds(1000 / kFps1); - } - // First QP value received, resets frames decoded. - const int kFps2 = 20; - for (int i = 0; i < metrics::kMinRunTimeInSeconds * kFps2; ++i) { - statistics_proxy_->OnDecodedFrame(frame, 1u, VideoContentType::UNSPECIFIED); - fake_clock_.AdvanceTimeMilliseconds(1000 / kFps2); - } - statistics_proxy_.reset(); - EXPECT_EQ(1, metrics::NumSamples("WebRTC.Video.DecodedFramesPerSecond")); - EXPECT_EQ(1, - metrics::NumEvents("WebRTC.Video.DecodedFramesPerSecond", kFps2)); -} - -TEST_F(ReceiveStatisticsProxyTest, OnDecodedFrameWithQpResetsFramesDecoded) { +TEST_F(ReceiveStatisticsProxyTest, + OnDecodedFrameWithQpDoesNotResetFramesDecodedOrTotalDecodeTime) { EXPECT_EQ(0u, statistics_proxy_->GetStats().frames_decoded); webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); + unsigned int expected_total_decode_time_ms = 0; + unsigned int expected_frames_decoded = 0; for (uint32_t i = 1; i <= 3; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 1, VideoContentType::UNSPECIFIED); - EXPECT_EQ(i, statistics_proxy_->GetStats().frames_decoded); + expected_total_decode_time_ms += 1; + ++expected_frames_decoded; + EXPECT_EQ(expected_frames_decoded, + statistics_proxy_->GetStats().frames_decoded); + EXPECT_EQ(expected_total_decode_time_ms, + statistics_proxy_->GetStats().total_decode_time_ms); } - statistics_proxy_->OnDecodedFrame(frame, 1u, VideoContentType::UNSPECIFIED); - EXPECT_EQ(1u, statistics_proxy_->GetStats().frames_decoded); + statistics_proxy_->OnDecodedFrame(frame, 1u, 3, + VideoContentType::UNSPECIFIED); + ++expected_frames_decoded; + expected_total_decode_time_ms += 3; + EXPECT_EQ(expected_frames_decoded, + statistics_proxy_->GetStats().frames_decoded); + EXPECT_EQ(expected_total_decode_time_ms, + statistics_proxy_->GetStats().total_decode_time_ms); } TEST_F(ReceiveStatisticsProxyTest, OnDecodedFrameIncreasesQpSum) { EXPECT_EQ(absl::nullopt, statistics_proxy_->GetStats().qp_sum); webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); - statistics_proxy_->OnDecodedFrame(frame, 3u, VideoContentType::UNSPECIFIED); + statistics_proxy_->OnDecodedFrame(frame, 3u, 0, + VideoContentType::UNSPECIFIED); EXPECT_EQ(3u, statistics_proxy_->GetStats().qp_sum); - statistics_proxy_->OnDecodedFrame(frame, 127u, VideoContentType::UNSPECIFIED); + statistics_proxy_->OnDecodedFrame(frame, 127u, 0, + VideoContentType::UNSPECIFIED); EXPECT_EQ(130u, statistics_proxy_->GetStats().qp_sum); } +TEST_F(ReceiveStatisticsProxyTest, OnDecodedFrameIncreasesTotalDecodeTime) { + EXPECT_EQ(absl::nullopt, statistics_proxy_->GetStats().qp_sum); + webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); + statistics_proxy_->OnDecodedFrame(frame, 3u, 4, + VideoContentType::UNSPECIFIED); + EXPECT_EQ(4u, statistics_proxy_->GetStats().total_decode_time_ms); + statistics_proxy_->OnDecodedFrame(frame, 127u, 7, + VideoContentType::UNSPECIFIED); + EXPECT_EQ(11u, statistics_proxy_->GetStats().total_decode_time_ms); +} + TEST_F(ReceiveStatisticsProxyTest, ReportsContentType) { const std::string kRealtimeString("realtime"); const std::string kScreenshareString("screen"); webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); EXPECT_EQ(kRealtimeString, videocontenttypehelpers::ToString( statistics_proxy_->GetStats().content_type)); - statistics_proxy_->OnDecodedFrame(frame, 3u, VideoContentType::SCREENSHARE); + statistics_proxy_->OnDecodedFrame(frame, 3u, 0, + VideoContentType::SCREENSHARE); EXPECT_EQ(kScreenshareString, videocontenttypehelpers::ToString( statistics_proxy_->GetStats().content_type)); - statistics_proxy_->OnDecodedFrame(frame, 3u, VideoContentType::UNSPECIFIED); + statistics_proxy_->OnDecodedFrame(frame, 3u, 0, + VideoContentType::UNSPECIFIED); EXPECT_EQ(kRealtimeString, videocontenttypehelpers::ToString( statistics_proxy_->GetStats().content_type)); } @@ -183,24 +192,24 @@ TEST_F(ReceiveStatisticsProxyTest, ReportsMaxInterframeDelay) { const int64_t kInterframeDelayMs2 = 200; const int64_t kInterframeDelayMs3 = 100; EXPECT_EQ(-1, statistics_proxy_->GetStats().interframe_delay_max_ms); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); EXPECT_EQ(-1, statistics_proxy_->GetStats().interframe_delay_max_ms); fake_clock_.AdvanceTimeMilliseconds(kInterframeDelayMs1); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); EXPECT_EQ(kInterframeDelayMs1, statistics_proxy_->GetStats().interframe_delay_max_ms); fake_clock_.AdvanceTimeMilliseconds(kInterframeDelayMs2); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); EXPECT_EQ(kInterframeDelayMs2, statistics_proxy_->GetStats().interframe_delay_max_ms); fake_clock_.AdvanceTimeMilliseconds(kInterframeDelayMs3); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); // kInterframeDelayMs3 is smaller than kInterframeDelayMs2. EXPECT_EQ(kInterframeDelayMs2, @@ -213,25 +222,25 @@ TEST_F(ReceiveStatisticsProxyTest, ReportInterframeDelayInWindow) { const int64_t kInterframeDelayMs2 = 750; const int64_t kInterframeDelayMs3 = 700; EXPECT_EQ(-1, statistics_proxy_->GetStats().interframe_delay_max_ms); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); EXPECT_EQ(-1, statistics_proxy_->GetStats().interframe_delay_max_ms); fake_clock_.AdvanceTimeMilliseconds(kInterframeDelayMs1); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); EXPECT_EQ(kInterframeDelayMs1, statistics_proxy_->GetStats().interframe_delay_max_ms); fake_clock_.AdvanceTimeMilliseconds(kInterframeDelayMs2); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); // Still first delay is the maximum EXPECT_EQ(kInterframeDelayMs1, statistics_proxy_->GetStats().interframe_delay_max_ms); fake_clock_.AdvanceTimeMilliseconds(kInterframeDelayMs3); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); // Now the first sample is out of the window, so the second is the maximum. EXPECT_EQ(kInterframeDelayMs2, @@ -342,19 +351,20 @@ TEST_F(ReceiveStatisticsProxyTest, ReportsSumSquaredFrameDurations) { TEST_F(ReceiveStatisticsProxyTest, OnDecodedFrameWithoutQpQpSumWontExist) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); EXPECT_EQ(absl::nullopt, statistics_proxy_->GetStats().qp_sum); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); EXPECT_EQ(absl::nullopt, statistics_proxy_->GetStats().qp_sum); } -TEST_F(ReceiveStatisticsProxyTest, OnDecodedFrameWithoutQpResetsQpSum) { +TEST_F(ReceiveStatisticsProxyTest, OnDecodedFrameWithoutQpDoesNotResetQpSum) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); EXPECT_EQ(absl::nullopt, statistics_proxy_->GetStats().qp_sum); - statistics_proxy_->OnDecodedFrame(frame, 3u, VideoContentType::UNSPECIFIED); - EXPECT_EQ(3u, statistics_proxy_->GetStats().qp_sum); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, 3u, 0, VideoContentType::UNSPECIFIED); - EXPECT_EQ(absl::nullopt, statistics_proxy_->GetStats().qp_sum); + EXPECT_EQ(3u, statistics_proxy_->GetStats().qp_sum); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, + VideoContentType::UNSPECIFIED); + EXPECT_EQ(3u, statistics_proxy_->GetStats().qp_sum); } TEST_F(ReceiveStatisticsProxyTest, OnRenderedFrameIncreasesFramesRendered) { @@ -394,7 +404,6 @@ TEST_F(ReceiveStatisticsProxyTest, GetStatsReportsOnCompleteFrame) { } TEST_F(ReceiveStatisticsProxyTest, GetStatsReportsDecodeTimingStats) { - const int kDecodeMs = 1; const int kMaxDecodeMs = 2; const int kCurrentDelayMs = 3; const int kTargetDelayMs = 4; @@ -404,10 +413,9 @@ TEST_F(ReceiveStatisticsProxyTest, GetStatsReportsDecodeTimingStats) { const int64_t kRttMs = 8; statistics_proxy_->OnRttUpdate(kRttMs, 0); statistics_proxy_->OnFrameBufferTimingsUpdated( - kDecodeMs, kMaxDecodeMs, kCurrentDelayMs, kTargetDelayMs, kJitterBufferMs, + kMaxDecodeMs, kCurrentDelayMs, kTargetDelayMs, kJitterBufferMs, kMinPlayoutDelayMs, kRenderDelayMs); VideoReceiveStream::Stats stats = statistics_proxy_->GetStats(); - EXPECT_EQ(kDecodeMs, stats.decode_ms); EXPECT_EQ(kMaxDecodeMs, stats.max_decode_ms); EXPECT_EQ(kCurrentDelayMs, stats.current_delay_ms); EXPECT_EQ(kTargetDelayMs, stats.target_delay_ms); @@ -774,7 +782,6 @@ TEST_F(ReceiveStatisticsProxyTest, KeyFrameHistogramIsUpdated) { } TEST_F(ReceiveStatisticsProxyTest, TimingHistogramsNotUpdatedForTooFewSamples) { - const int kDecodeMs = 1; const int kMaxDecodeMs = 2; const int kCurrentDelayMs = 3; const int kTargetDelayMs = 4; @@ -784,8 +791,8 @@ TEST_F(ReceiveStatisticsProxyTest, TimingHistogramsNotUpdatedForTooFewSamples) { for (int i = 0; i < kMinRequiredSamples - 1; ++i) { statistics_proxy_->OnFrameBufferTimingsUpdated( - kDecodeMs, kMaxDecodeMs, kCurrentDelayMs, kTargetDelayMs, - kJitterBufferMs, kMinPlayoutDelayMs, kRenderDelayMs); + kMaxDecodeMs, kCurrentDelayMs, kTargetDelayMs, kJitterBufferMs, + kMinPlayoutDelayMs, kRenderDelayMs); } statistics_proxy_.reset(); @@ -797,7 +804,6 @@ TEST_F(ReceiveStatisticsProxyTest, TimingHistogramsNotUpdatedForTooFewSamples) { } TEST_F(ReceiveStatisticsProxyTest, TimingHistogramsAreUpdated) { - const int kDecodeMs = 1; const int kMaxDecodeMs = 2; const int kCurrentDelayMs = 3; const int kTargetDelayMs = 4; @@ -807,18 +813,16 @@ TEST_F(ReceiveStatisticsProxyTest, TimingHistogramsAreUpdated) { for (int i = 0; i < kMinRequiredSamples; ++i) { statistics_proxy_->OnFrameBufferTimingsUpdated( - kDecodeMs, kMaxDecodeMs, kCurrentDelayMs, kTargetDelayMs, - kJitterBufferMs, kMinPlayoutDelayMs, kRenderDelayMs); + kMaxDecodeMs, kCurrentDelayMs, kTargetDelayMs, kJitterBufferMs, + kMinPlayoutDelayMs, kRenderDelayMs); } statistics_proxy_.reset(); - EXPECT_EQ(1, metrics::NumSamples("WebRTC.Video.DecodeTimeInMs")); EXPECT_EQ(1, metrics::NumSamples("WebRTC.Video.JitterBufferDelayInMs")); EXPECT_EQ(1, metrics::NumSamples("WebRTC.Video.TargetDelayInMs")); EXPECT_EQ(1, metrics::NumSamples("WebRTC.Video.CurrentDelayInMs")); EXPECT_EQ(1, metrics::NumSamples("WebRTC.Video.OnewayDelayInMs")); - EXPECT_EQ(1, metrics::NumEvents("WebRTC.Video.DecodeTimeInMs", kDecodeMs)); EXPECT_EQ(1, metrics::NumEvents("WebRTC.Video.JitterBufferDelayInMs", kJitterBufferMs)); EXPECT_EQ(1, @@ -837,7 +841,7 @@ TEST_F(ReceiveStatisticsProxyTest, DoesNotReportStaleFramerates) { // Since OnRenderedFrame is never called the fps in each sample will be 0, // i.e. bad frame.set_ntp_time_ms(fake_clock_.CurrentNtpInMilliseconds()); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); statistics_proxy_->OnRenderedFrame(frame); fake_clock_.AdvanceTimeMilliseconds(1000 / kDefaultFps); @@ -893,7 +897,7 @@ TEST_F(ReceiveStatisticsProxyTest, ReceivedFrameHistogramsAreUpdated) { TEST_F(ReceiveStatisticsProxyTest, ZeroDelayReportedIfFrameNotDelayed) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); // Frame not delayed, delayed frames to render: 0%. @@ -912,7 +916,7 @@ TEST_F(ReceiveStatisticsProxyTest, ZeroDelayReportedIfFrameNotDelayed) { TEST_F(ReceiveStatisticsProxyTest, DelayedFrameHistogramsAreNotUpdatedIfMinRuntimeHasNotPassed) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); // Frame not delayed, delayed frames to render: 0%. @@ -931,7 +935,7 @@ TEST_F(ReceiveStatisticsProxyTest, TEST_F(ReceiveStatisticsProxyTest, DelayedFramesHistogramsAreNotUpdatedIfNoRenderedFrames) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); // Min run time has passed. No rendered frames. @@ -944,7 +948,7 @@ TEST_F(ReceiveStatisticsProxyTest, TEST_F(ReceiveStatisticsProxyTest, DelayReportedIfFrameIsDelayed) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); // Frame delayed 1 ms, delayed frames to render: 100%. @@ -964,7 +968,7 @@ TEST_F(ReceiveStatisticsProxyTest, DelayReportedIfFrameIsDelayed) { TEST_F(ReceiveStatisticsProxyTest, AverageDelayOfDelayedFramesIsReported) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, VideoContentType::UNSPECIFIED); // Two frames delayed (6 ms, 10 ms), delayed frames to render: 50%. @@ -1099,12 +1103,12 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, InterFrameDelaysAreReported) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (int i = 0; i < kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } // One extra with double the interval. fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_.reset(); const int kExpectedInterFrame = @@ -1134,16 +1138,16 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, for (int i = 0; i <= kMinRequiredSamples - kLastFivePercentsSamples; ++i) { fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); } // Last 5% of intervals are double in size. for (int i = 0; i < kLastFivePercentsSamples; ++i) { fake_clock_.AdvanceTimeMilliseconds(2 * kInterFrameDelayMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); } // Final sample is outlier and 10 times as big. fake_clock_.AdvanceTimeMilliseconds(10 * kInterFrameDelayMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_.reset(); const int kExpectedInterFrame = kInterFrameDelayMs * 2; @@ -1164,7 +1168,7 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (int i = 0; i < kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } @@ -1184,7 +1188,7 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, MaxInterFrameDelayOnlyWithPause) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (int i = 0; i <= kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } @@ -1195,9 +1199,9 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, MaxInterFrameDelayOnlyWithPause) { // Insert two more frames. The interval during the pause should be disregarded // in the stats. - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_.reset(); if (videocontenttypehelpers::IsScreenshare(content_type_)) { @@ -1229,13 +1233,13 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, FreezesAreReported) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (int i = 0; i < kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } // Add extra freeze. fake_clock_.AdvanceTimeMilliseconds(kFreezeDelayMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); statistics_proxy_.reset(); @@ -1272,20 +1276,20 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, HarmonicFrameRateIsReported) { for (int i = 0; i < kMinRequiredSamples; ++i) { fake_clock_.AdvanceTimeMilliseconds(kFrameDurationMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); } // Freezes and pauses should be included into harmonic frame rate. // Add freeze. fake_clock_.AdvanceTimeMilliseconds(kFreezeDurationMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); // Add pause. fake_clock_.AdvanceTimeMilliseconds(kPauseDurationMs); statistics_proxy_->OnStreamInactive(); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); statistics_proxy_.reset(); @@ -1313,7 +1317,7 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, PausesAreIgnored) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (int i = 0; i <= kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } @@ -1323,7 +1327,7 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, PausesAreIgnored) { // Second playback interval with triple the length. for (int i = 0; i <= kMinRequiredSamples * 3; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } @@ -1351,13 +1355,13 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, ManyPausesAtTheBeginning) { webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); for (int i = 0; i <= kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); statistics_proxy_->OnStreamInactive(); fake_clock_.AdvanceTimeMilliseconds(kPauseDurationMs); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type_); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } @@ -1378,13 +1382,15 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, TimeInHdReported) { // HD frames. for (int i = 0; i < kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame_hd, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame_hd, absl::nullopt, 0, + content_type_); statistics_proxy_->OnRenderedFrame(frame_hd); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } // SD frames. for (int i = 0; i < 2 * kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame_sd, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame_sd, absl::nullopt, 0, + content_type_); statistics_proxy_->OnRenderedFrame(frame_sd); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } @@ -1411,18 +1417,18 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, TimeInBlockyVideoReported) { // High quality frames. for (int i = 0; i < kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, kLowQp, content_type_); + statistics_proxy_->OnDecodedFrame(frame, kLowQp, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } // Blocky frames. for (int i = 0; i < 2 * kMinRequiredSamples; ++i) { - statistics_proxy_->OnDecodedFrame(frame, kHighQp, content_type_); + statistics_proxy_->OnDecodedFrame(frame, kHighQp, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); } // Extra last frame. - statistics_proxy_->OnDecodedFrame(frame, kHighQp, content_type_); + statistics_proxy_->OnDecodedFrame(frame, kHighQp, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame); statistics_proxy_.reset(); @@ -1445,7 +1451,7 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, DownscalesReported) { webrtc::VideoFrame frame_ld = CreateFrame(320, 180); // Call once to pass content type. - statistics_proxy_->OnDecodedFrame(frame_hd, absl::nullopt, content_type_); + statistics_proxy_->OnDecodedFrame(frame_hd, absl::nullopt, 0, content_type_); statistics_proxy_->OnRenderedFrame(frame_hd); fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); @@ -1472,6 +1478,21 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, DownscalesReported) { } } +TEST_P(ReceiveStatisticsProxyTestWithContent, DecodeTimeReported) { + const int kInterFrameDelayMs = 20; + const int kLowQp = 30; + const int kDecodeMs = 7; + + webrtc::VideoFrame frame = CreateFrame(kWidth, kHeight); + + for (int i = 0; i < kMinRequiredSamples; ++i) { + statistics_proxy_->OnDecodedFrame(frame, kLowQp, kDecodeMs, content_type_); + fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs); + } + statistics_proxy_.reset(); + EXPECT_EQ(1, metrics::NumEvents("WebRTC.Video.DecodeTimeInMs", kDecodeMs)); +} + TEST_P(ReceiveStatisticsProxyTestWithContent, StatsAreSlicedOnSimulcastAndExperiment) { const uint8_t experiment_id = 1; @@ -1484,13 +1505,13 @@ TEST_P(ReceiveStatisticsProxyTestWithContent, videocontenttypehelpers::SetSimulcastId(&content_type, 1); for (int i = 0; i <= kMinRequiredSamples; ++i) { fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs1); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type); } videocontenttypehelpers::SetSimulcastId(&content_type, 2); for (int i = 0; i <= kMinRequiredSamples; ++i) { fake_clock_.AdvanceTimeMilliseconds(kInterFrameDelayMs2); - statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, content_type); + statistics_proxy_->OnDecodedFrame(frame, absl::nullopt, 0, content_type); } statistics_proxy_.reset(); diff --git a/video/video_stream_decoder.cc b/video/video_stream_decoder.cc index 0c4eeeb643..c523a4759c 100644 --- a/video/video_stream_decoder.cc +++ b/video/video_stream_decoder.cc @@ -44,8 +44,10 @@ VideoStreamDecoder::~VideoStreamDecoder() { // Release. Acquiring the same lock in the path of decode callback can deadlock. int32_t VideoStreamDecoder::FrameToRender(VideoFrame& video_frame, absl::optional qp, + int32_t decode_time_ms, VideoContentType content_type) { - receive_stats_callback_->OnDecodedFrame(video_frame, qp, content_type); + receive_stats_callback_->OnDecodedFrame(video_frame, qp, decode_time_ms, + content_type); incoming_video_stream_->OnFrame(video_frame); return 0; } diff --git a/video/video_stream_decoder.h b/video/video_stream_decoder.h index 50b0c8c7ce..b8ad933d9f 100644 --- a/video/video_stream_decoder.h +++ b/video/video_stream_decoder.h @@ -42,6 +42,7 @@ class VideoStreamDecoder : public VCMReceiveCallback { // Implements VCMReceiveCallback. int32_t FrameToRender(VideoFrame& video_frame, absl::optional qp, + int32_t decode_time_ms, VideoContentType content_type) override; void OnIncomingPayloadType(int payload_type) override; void OnDecoderImplementationName(const char* implementation_name) override; diff --git a/video/video_stream_decoder_impl.cc b/video/video_stream_decoder_impl.cc index b4ae8488d9..003f23018f 100644 --- a/video/video_stream_decoder_impl.cc +++ b/video/video_stream_decoder_impl.cc @@ -277,8 +277,7 @@ void VideoStreamDecoderImpl::Decoded(VideoFrame& decoded_image, absl::optional casted_decode_time_ms(decode_time_ms.value_or( decode_stop_time_ms - frame_timestamps->decode_start_time_ms)); - timing_.StopDecodeTimer(0, *casted_decode_time_ms, decode_stop_time_ms, - frame_timestamps->render_time_us / 1000); + timing_.StopDecodeTimer(*casted_decode_time_ms, decode_stop_time_ms); VideoFrame copy = decoded_image; copy.set_timestamp_us(frame_timestamps->render_time_us);