From 514f084c26039a587dac471e483d8295e6196dfc Mon Sep 17 00:00:00 2001 From: Benjamin Wright Date: Mon, 10 Dec 2018 09:55:17 -0800 Subject: [PATCH] New statistic added to VideoReceiveStream to determine latency to first decode. This change introduces a new measurement into the VideoReceiveStream::Stats structure to measure the latency between the first frame being received and the first frame being decoded in WebRTC. The goal here is to measure the latency difference when a FrameEncryptor is attached and not attached. Change-Id: I0f0178aff73b66f25dbc6617098033e226da2958 Bug: webrtc:10105 Reviewed-on: https://webrtc-review.googlesource.com/c/113328 Commit-Queue: Benjamin Wright Reviewed-by: Steve Anton Reviewed-by: Niels Moller Reviewed-by: Ilya Nikolaevskiy Cr-Commit-Position: refs/heads/master@{#25956} --- api/statstypes.cc | 2 ++ api/statstypes.h | 1 + call/video_receive_stream.cc | 4 +++- call/video_receive_stream.h | 1 + media/base/mediachannel.h | 3 +++ media/engine/webrtcvideoengine.cc | 3 ++- pc/statscollector.cc | 4 ++++ video/receive_statistics_proxy.cc | 14 +++++++++++++- video/receive_statistics_proxy.h | 1 + 9 files changed, 30 insertions(+), 3 deletions(-) diff --git a/api/statstypes.cc b/api/statstypes.cc index ad68894f48..dc37abcb29 100644 --- a/api/statstypes.cc +++ b/api/statstypes.cc @@ -516,6 +516,8 @@ const char* StatsReport::Value::display_name() const { return "googFirsReceived"; case kStatsValueNameFirsSent: return "googFirsSent"; + case kStatsValueNameFirstFrameReceivedToDecodedMs: + return "googFirstFrameReceivedToDecodedMs"; case kStatsValueNameFrameHeightInput: return "googFrameHeightInput"; case kStatsValueNameFrameHeightReceived: diff --git a/api/statstypes.h b/api/statstypes.h index 857b1afaa7..e653d15bf2 100644 --- a/api/statstypes.h +++ b/api/statstypes.h @@ -176,6 +176,7 @@ class StatsReport { kStatsValueNameFingerprintAlgorithm, kStatsValueNameFirsReceived, kStatsValueNameFirsSent, + kStatsValueNameFirstFrameReceivedToDecodedMs, kStatsValueNameFrameHeightInput, kStatsValueNameFrameHeightReceived, kStatsValueNameFrameHeightSent, diff --git a/call/video_receive_stream.cc b/call/video_receive_stream.cc index 672abd83bb..49845237df 100644 --- a/call/video_receive_stream.cc +++ b/call/video_receive_stream.cc @@ -35,7 +35,7 @@ VideoReceiveStream::Stats::Stats() = default; VideoReceiveStream::Stats::~Stats() = default; std::string VideoReceiveStream::Stats::ToString(int64_t time_ms) const { - char buf[1024]; + char buf[2048]; rtc::SimpleStringBuilder ss(buf); ss << "VideoReceiveStream stats: " << time_ms << ", {ssrc: " << ssrc << ", "; ss << "total_bps: " << total_bitrate_bps << ", "; @@ -48,6 +48,8 @@ std::string VideoReceiveStream::Stats::ToString(int64_t time_ms) const { ss << "render_fps: " << render_frame_rate << ", "; ss << "decode_ms: " << decode_ms << ", "; ss << "max_decode_ms: " << max_decode_ms << ", "; + ss << "first_frame_received_to_decoded_ms: " + << first_frame_received_to_decoded_ms << ", "; ss << "cur_delay_ms: " << current_delay_ms << ", "; ss << "targ_delay_ms: " << target_delay_ms << ", "; ss << "jb_delay_ms: " << jitter_buffer_ms << ", "; diff --git a/call/video_receive_stream.h b/call/video_receive_stream.h index 2cd5f1631a..8388356f35 100644 --- a/call/video_receive_stream.h +++ b/call/video_receive_stream.h @@ -78,6 +78,7 @@ class VideoReceiveStream { int render_delay_ms = 10; int64_t interframe_delay_max_ms = -1; uint32_t frames_decoded = 0; + int64_t first_frame_received_to_decoded_ms = -1; absl::optional qp_sum; int current_payload_type = -1; diff --git a/media/base/mediachannel.h b/media/base/mediachannel.h index fca6ee4dd9..09e752a343 100644 --- a/media/base/mediachannel.h +++ b/media/base/mediachannel.h @@ -558,6 +558,9 @@ struct VideoReceiverInfo : public MediaReceiverInfo { // Estimated capture start time in NTP time in ms. int64_t capture_start_ntp_time_ms = -1; + // First frame received to first frame decoded latency. + int64_t first_frame_received_to_decoded_ms = -1; + // Timing frame info: all important timestamps for a full lifetime of a // single 'timing frame'. absl::optional timing_frame_info; diff --git a/media/engine/webrtcvideoengine.cc b/media/engine/webrtcvideoengine.cc index c5e4cdf67c..e4292314b8 100644 --- a/media/engine/webrtcvideoengine.cc +++ b/media/engine/webrtcvideoengine.cc @@ -2532,7 +2532,8 @@ WebRtcVideoChannel::WebRtcVideoReceiveStream::GetVideoReceiverInfo( info.frames_decoded = stats.frames_decoded; info.frames_rendered = stats.frames_rendered; info.qp_sum = stats.qp_sum; - + info.first_frame_received_to_decoded_ms = + stats.first_frame_received_to_decoded_ms; info.interframe_delay_max_ms = stats.interframe_delay_max_ms; info.content_type = stats.content_type; diff --git a/pc/statscollector.cc b/pc/statscollector.cc index 3cd85e69b2..c08633b48e 100644 --- a/pc/statscollector.cc +++ b/pc/statscollector.cc @@ -252,6 +252,10 @@ void ExtractStats(const cricket::VideoReceiverInfo& info, StatsReport* report) { report->AddInt64(StatsReport::kStatsValueNameCaptureStartNtpTimeMs, info.capture_start_ntp_time_ms); } + if (info.first_frame_received_to_decoded_ms >= 0) { + report->AddInt64(StatsReport::kStatsValueNameFirstFrameReceivedToDecodedMs, + info.first_frame_received_to_decoded_ms); + } if (info.qp_sum) report->AddInt64(StatsReport::kStatsValueNameQpSum, *info.qp_sum); diff --git a/video/receive_statistics_proxy.cc b/video/receive_statistics_proxy.cc index 8d398871cc..3cdbc2da6f 100644 --- a/video/receive_statistics_proxy.cc +++ b/video/receive_statistics_proxy.cc @@ -642,6 +642,17 @@ void ReceiveStatisticsProxy::OnTimingFrameInfoUpdated( int64_t now_ms = clock_->TimeInMilliseconds(); timing_frame_info_counter_.Add(info, now_ms); } + + // Measure initial decoding latency between the first frame arriving and the + // first frame being decoded. + if (!first_frame_received_time_ms_.has_value()) { + first_frame_received_time_ms_ = info.receive_finish_ms; + } + if (stats_.first_frame_received_to_decoded_ms == -1 && + first_decoded_frame_time_ms_) { + stats_.first_frame_received_to_decoded_ms = + *first_decoded_frame_time_ms_ - *first_frame_received_time_ms_; + } } void ReceiveStatisticsProxy::RtcpPacketTypesCounterUpdated( @@ -749,8 +760,9 @@ void ReceiveStatisticsProxy::OnDecodedFrame(absl::optional qp, interframe_delay_ms); content_specific_stats->flow_duration_ms += interframe_delay_ms; } - if (stats_.frames_decoded == 1) + if (stats_.frames_decoded == 1) { first_decoded_frame_time_ms_.emplace(now); + } last_decoded_frame_time_ms_.emplace(now); } diff --git a/video/receive_statistics_proxy.h b/video/receive_statistics_proxy.h index 100e75116c..84c4e01b4e 100644 --- a/video/receive_statistics_proxy.h +++ b/video/receive_statistics_proxy.h @@ -181,6 +181,7 @@ class ReceiveStatisticsProxy : public VCMReceiveStatisticsCallback, mutable std::map frame_window_ RTC_GUARDED_BY(&crit_); VideoContentType last_content_type_ RTC_GUARDED_BY(&crit_); VideoCodecType last_codec_type_ RTC_GUARDED_BY(&crit_); + absl::optional first_frame_received_time_ms_ RTC_GUARDED_BY(&crit_); absl::optional first_decoded_frame_time_ms_ RTC_GUARDED_BY(&crit_); absl::optional last_decoded_frame_time_ms_ RTC_GUARDED_BY(&crit_); size_t num_delayed_frames_rendered_ RTC_GUARDED_BY(&crit_);