From 9fe1834d5d0962ef5b5e075d4da520e8c235081b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Henrik=20Bostr=C3=B6m?= Date: Thu, 16 May 2019 18:38:20 +0200 Subject: [PATCH] Implement RTCOutboundRtpStreamStats.totalPacketSendDelay for video. MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This is a standardized metric. Spec: https://w3c.github.io/webrtc-stats/#dom-rtcoutboundrtpstreamstats-totalpacketsenddelay It is meant to replace the legacy googBucketDelay. The average packet delay over any interval can be calculated as the delta totalPacketSendDelay divided by the delta packetsSent between two calls to getStats(). Bug: webrtc:10506 Change-Id: I3d6c6d66e5a06937d0ea8d182a82cd255084ad19 Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/137044 Reviewed-by: Stefan Holmer Commit-Queue: Henrik Boström Cr-Commit-Position: refs/heads/master@{#27979} --- api/stats/rtcstats_objects.h | 3 +++ call/video_send_stream.h | 1 + media/base/media_channel.h | 1 + media/engine/webrtc_video_engine.cc | 2 ++ modules/rtp_rtcp/include/rtp_rtcp_defines.h | 1 + modules/rtp_rtcp/source/rtp_sender.cc | 8 +++++-- modules/rtp_rtcp/source/rtp_sender.h | 3 +++ .../rtp_rtcp/source/rtp_sender_unittest.cc | 24 +++++++++++-------- pc/rtc_stats_collector.cc | 3 +++ pc/rtc_stats_collector_unittest.cc | 2 ++ pc/rtc_stats_integrationtest.cc | 4 ++++ stats/rtcstats_objects.cc | 3 +++ video/send_statistics_proxy.cc | 2 ++ video/send_statistics_proxy.h | 1 + video/send_statistics_proxy_unittest.cc | 12 ++++++++-- 15 files changed, 56 insertions(+), 14 deletions(-) diff --git a/api/stats/rtcstats_objects.h b/api/stats/rtcstats_objects.h index d614a869f2..8f8eb203d5 100644 --- a/api/stats/rtcstats_objects.h +++ b/api/stats/rtcstats_objects.h @@ -458,6 +458,9 @@ class RTC_EXPORT RTCOutboundRTPStreamStats final : public RTCRTPStreamStats { RTCStatsMember target_bitrate; RTCStatsMember frames_encoded; RTCStatsMember total_encode_time; + // TODO(https://crbug.com/webrtc/10635): This is only implemented for video; + // implement it for audio as well. + RTCStatsMember total_packet_send_delay; // https://henbos.github.io/webrtc-provisional-stats/#dom-rtcoutboundrtpstreamstats-contenttype RTCStatsMember content_type; }; diff --git a/call/video_send_stream.h b/call/video_send_stream.h index 8f550daa9c..a06024a177 100644 --- a/call/video_send_stream.h +++ b/call/video_send_stream.h @@ -53,6 +53,7 @@ class VideoSendStream { int retransmit_bitrate_bps = 0; int avg_delay_ms = 0; int max_delay_ms = 0; + uint64_t total_packet_send_delay_ms = 0; StreamDataCounters rtp_stats; RtcpPacketTypeCounter rtcp_packet_type_counts; RtcpStatistics rtcp_stats; diff --git a/media/base/media_channel.h b/media/base/media_channel.h index 15721c5948..4930d416fc 100644 --- a/media/base/media_channel.h +++ b/media/base/media_channel.h @@ -546,6 +546,7 @@ struct VideoSenderInfo : public MediaSenderInfo { uint32_t frames_encoded = 0; // https://w3c.github.io/webrtc-stats/#dom-rtcoutboundrtpstreamstats-totalencodetime uint64_t total_encode_time_ms = 0; + uint64_t total_packet_send_delay_ms = 0; bool has_entered_low_resolution = false; absl::optional qp_sum; webrtc::VideoContentType content_type = webrtc::VideoContentType::UNSPECIFIED; diff --git a/media/engine/webrtc_video_engine.cc b/media/engine/webrtc_video_engine.cc index 234c7abc2d..1f5e3023b1 100644 --- a/media/engine/webrtc_video_engine.cc +++ b/media/engine/webrtc_video_engine.cc @@ -2262,6 +2262,7 @@ VideoSenderInfo WebRtcVideoChannel::WebRtcVideoSendStream::GetVideoSenderInfo( info.send_frame_width = 0; info.send_frame_height = 0; + info.total_packet_send_delay_ms = 0; for (std::map::iterator it = stats.substreams.begin(); it != stats.substreams.end(); ++it) { @@ -2273,6 +2274,7 @@ VideoSenderInfo WebRtcVideoChannel::WebRtcVideoSendStream::GetVideoSenderInfo( stream_stats.rtp_stats.transmitted.header_bytes + stream_stats.rtp_stats.transmitted.padding_bytes; info.packets_sent += stream_stats.rtp_stats.transmitted.packets; + info.total_packet_send_delay_ms += stream_stats.total_packet_send_delay_ms; // TODO(https://crbug.com/webrtc/10555): RTX retransmissions should show up // in separate outbound-rtp stream objects. if (!stream_stats.is_rtx && !stream_stats.is_flexfec) { diff --git a/modules/rtp_rtcp/include/rtp_rtcp_defines.h b/modules/rtp_rtcp/include/rtp_rtcp_defines.h index d44a366bc0..1ca7b9a3aa 100644 --- a/modules/rtp_rtcp/include/rtp_rtcp_defines.h +++ b/modules/rtp_rtcp/include/rtp_rtcp_defines.h @@ -532,6 +532,7 @@ class SendSideDelayObserver { virtual ~SendSideDelayObserver() {} virtual void SendSideDelayUpdated(int avg_delay_ms, int max_delay_ms, + uint64_t total_delay_ms, uint32_t ssrc) = 0; }; diff --git a/modules/rtp_rtcp/source/rtp_sender.cc b/modules/rtp_rtcp/source/rtp_sender.cc index 56d42aad90..044148db14 100644 --- a/modules/rtp_rtcp/source/rtp_sender.cc +++ b/modules/rtp_rtcp/source/rtp_sender.cc @@ -124,6 +124,7 @@ RTPSender::RTPSender( send_delays_(), max_delay_it_(send_delays_.end()), sum_delays_ms_(0), + total_packet_send_delay_ms_(0), rtp_stats_callback_(nullptr), total_bitrate_sent_(kBitrateStatisticsWindowMs, RateStatistics::kBpsScale), @@ -774,6 +775,7 @@ void RTPSender::UpdateDelayStatistics(int64_t capture_time_ms, int64_t now_ms) { uint32_t ssrc; int avg_delay_ms = 0; int max_delay_ms = 0; + uint64_t total_packet_send_delay_ms = 0; { rtc::CritScope lock(&send_critsect_); if (!ssrc_) @@ -831,6 +833,8 @@ void RTPSender::UpdateDelayStatistics(int64_t capture_time_ms, int64_t now_ms) { max_delay_it_ = it; } sum_delays_ms_ += new_send_delay; + total_packet_send_delay_ms_ += new_send_delay; + total_packet_send_delay_ms = total_packet_send_delay_ms_; size_t num_delays = send_delays_.size(); RTC_DCHECK(max_delay_it_ != send_delays_.end()); @@ -842,8 +846,8 @@ void RTPSender::UpdateDelayStatistics(int64_t capture_time_ms, int64_t now_ms) { avg_delay_ms = rtc::dchecked_cast((sum_delays_ms_ + num_delays / 2) / num_delays); } - send_side_delay_observer_->SendSideDelayUpdated(avg_delay_ms, max_delay_ms, - ssrc); + send_side_delay_observer_->SendSideDelayUpdated( + avg_delay_ms, max_delay_ms, total_packet_send_delay_ms, ssrc); } void RTPSender::UpdateOnSendPacket(int packet_id, diff --git a/modules/rtp_rtcp/source/rtp_sender.h b/modules/rtp_rtcp/source/rtp_sender.h index 66b821fc26..8c6d01266e 100644 --- a/modules/rtp_rtcp/source/rtp_sender.h +++ b/modules/rtp_rtcp/source/rtp_sender.h @@ -255,7 +255,10 @@ class RTPSender : public AcknowledgedPacketsObserver { rtc::CriticalSection statistics_crit_; SendDelayMap send_delays_ RTC_GUARDED_BY(statistics_crit_); SendDelayMap::const_iterator max_delay_it_ RTC_GUARDED_BY(statistics_crit_); + // The sum of delays over a kSendSideDelayWindowMs sliding window. int64_t sum_delays_ms_ RTC_GUARDED_BY(statistics_crit_); + // The sum of delays of all packets sent. + uint64_t total_packet_send_delay_ms_ RTC_GUARDED_BY(statistics_crit_); StreamDataCounters rtp_stats_ RTC_GUARDED_BY(statistics_crit_); StreamDataCounters rtx_rtp_stats_ RTC_GUARDED_BY(statistics_crit_); StreamDataCountersCallback* rtp_stats_callback_ diff --git a/modules/rtp_rtcp/source/rtp_sender_unittest.cc b/modules/rtp_rtcp/source/rtp_sender_unittest.cc index fc2fe82a36..9ac23fc478 100644 --- a/modules/rtp_rtcp/source/rtp_sender_unittest.cc +++ b/modules/rtp_rtcp/source/rtp_sender_unittest.cc @@ -154,7 +154,7 @@ class MockTransportSequenceNumberAllocator class MockSendSideDelayObserver : public SendSideDelayObserver { public: - MOCK_METHOD3(SendSideDelayUpdated, void(int, int, uint32_t)); + MOCK_METHOD4(SendSideDelayUpdated, void(int, int, uint64_t, uint32_t)); }; class MockSendPacketObserver : public SendPacketObserver { @@ -526,9 +526,10 @@ TEST_P(RtpSenderTestWithoutPacer, OnSendSideDelayUpdated) { const uint32_t kCaptureTimeMsToRtpTimestamp = 90; // 90 kHz clock RTPVideoHeader video_header; - // Send packet with 10 ms send-side delay. The average and max should be 10 - // ms. - EXPECT_CALL(send_side_delay_observer_, SendSideDelayUpdated(10, 10, kSsrc)) + // Send packet with 10 ms send-side delay. The average, max and total should + // be 10 ms. + EXPECT_CALL(send_side_delay_observer_, + SendSideDelayUpdated(10, 10, 10, kSsrc)) .Times(1); int64_t capture_time_ms = fake_clock_.TimeInMilliseconds(); fake_clock_.AdvanceTimeMilliseconds(10); @@ -538,9 +539,10 @@ TEST_P(RtpSenderTestWithoutPacer, OnSendSideDelayUpdated) { kPayloadData, sizeof(kPayloadData), nullptr, &video_header, kDefaultExpectedRetransmissionTimeMs)); - // Send another packet with 20 ms delay. The average - // and max should be 15 and 20 ms respectively. - EXPECT_CALL(send_side_delay_observer_, SendSideDelayUpdated(15, 20, kSsrc)) + // Send another packet with 20 ms delay. The average, max and total should be + // 15, 20 and 30 ms respectively. + EXPECT_CALL(send_side_delay_observer_, + SendSideDelayUpdated(15, 20, 30, kSsrc)) .Times(1); fake_clock_.AdvanceTimeMilliseconds(10); EXPECT_TRUE(rtp_sender_video.SendVideo( @@ -551,8 +553,9 @@ TEST_P(RtpSenderTestWithoutPacer, OnSendSideDelayUpdated) { // Send another packet at the same time, which replaces the last packet. // Since this packet has 0 ms delay, the average is now 5 ms and max is 10 ms. + // The total counter stays the same though. // TODO(terelius): Is is not clear that this is the right behavior. - EXPECT_CALL(send_side_delay_observer_, SendSideDelayUpdated(5, 10, kSsrc)) + EXPECT_CALL(send_side_delay_observer_, SendSideDelayUpdated(5, 10, 30, kSsrc)) .Times(1); capture_time_ms = fake_clock_.TimeInMilliseconds(); EXPECT_TRUE(rtp_sender_video.SendVideo( @@ -562,11 +565,12 @@ TEST_P(RtpSenderTestWithoutPacer, OnSendSideDelayUpdated) { kDefaultExpectedRetransmissionTimeMs)); // Send a packet 1 second later. The earlier packets should have timed - // out, so both max and average should be the delay of this packet. + // out, so both max and average should be the delay of this packet. The total + // keeps increasing. fake_clock_.AdvanceTimeMilliseconds(1000); capture_time_ms = fake_clock_.TimeInMilliseconds(); fake_clock_.AdvanceTimeMilliseconds(1); - EXPECT_CALL(send_side_delay_observer_, SendSideDelayUpdated(1, 1, kSsrc)) + EXPECT_CALL(send_side_delay_observer_, SendSideDelayUpdated(1, 1, 31, kSsrc)) .Times(1); EXPECT_TRUE(rtp_sender_video.SendVideo( VideoFrameType::kVideoFrameKey, kPayloadType, diff --git a/pc/rtc_stats_collector.cc b/pc/rtc_stats_collector.cc index 0d1fbba25a..06618486cd 100644 --- a/pc/rtc_stats_collector.cc +++ b/pc/rtc_stats_collector.cc @@ -347,6 +347,9 @@ void SetOutboundRTPStreamStatsFromVideoSenderInfo( outbound_video->total_encode_time = static_cast(video_sender_info.total_encode_time_ms) / rtc::kNumMillisecsPerSec; + outbound_video->total_packet_send_delay = + static_cast(video_sender_info.total_packet_send_delay_ms) / + rtc::kNumMillisecsPerSec; // TODO(https://crbug.com/webrtc/10529): When info's |content_info| is // optional, support the "unspecified" value. if (video_sender_info.content_type == VideoContentType::SCREENSHARE) diff --git a/pc/rtc_stats_collector_unittest.cc b/pc/rtc_stats_collector_unittest.cc index a6531d2ac8..312e309262 100644 --- a/pc/rtc_stats_collector_unittest.cc +++ b/pc/rtc_stats_collector_unittest.cc @@ -1849,6 +1849,7 @@ TEST_F(RTCStatsCollectorTest, CollectRTCOutboundRTPStreamStats_Video) { video_media_info.senders[0].codec_payload_type = 42; video_media_info.senders[0].frames_encoded = 8; video_media_info.senders[0].total_encode_time_ms = 9000; + video_media_info.senders[0].total_packet_send_delay_ms = 10000; video_media_info.senders[0].qp_sum = absl::nullopt; video_media_info.senders[0].content_type = VideoContentType::UNSPECIFIED; @@ -1890,6 +1891,7 @@ TEST_F(RTCStatsCollectorTest, CollectRTCOutboundRTPStreamStats_Video) { expected_video.retransmitted_bytes_sent = 60; expected_video.frames_encoded = 8; expected_video.total_encode_time = 9.0; + expected_video.total_packet_send_delay = 10.0; // |expected_video.content_type| should be undefined. // |expected_video.qp_sum| should be undefined. ASSERT_TRUE(report->Get(expected_video.id())); diff --git a/pc/rtc_stats_integrationtest.cc b/pc/rtc_stats_integrationtest.cc index a7515993a9..ebb2f38090 100644 --- a/pc/rtc_stats_integrationtest.cc +++ b/pc/rtc_stats_integrationtest.cc @@ -793,12 +793,16 @@ class RTCStatsReportVerifier { verifier.TestMemberIsDefined(outbound_stream.frames_encoded); verifier.TestMemberIsNonNegative( outbound_stream.total_encode_time); + verifier.TestMemberIsNonNegative( + outbound_stream.total_packet_send_delay); // The integration test is not set up to test screen share; don't require // this to be present. verifier.MarkMemberTested(outbound_stream.content_type, true); } else { verifier.TestMemberIsUndefined(outbound_stream.frames_encoded); verifier.TestMemberIsUndefined(outbound_stream.total_encode_time); + // TODO(https://crbug.com/webrtc/10635): Implement for audio as well. + verifier.TestMemberIsUndefined(outbound_stream.total_packet_send_delay); verifier.TestMemberIsUndefined(outbound_stream.content_type); } return verifier.ExpectAllMembersSuccessfullyTested(); diff --git a/stats/rtcstats_objects.cc b/stats/rtcstats_objects.cc index 2aa2cd2e28..40a28747c0 100644 --- a/stats/rtcstats_objects.cc +++ b/stats/rtcstats_objects.cc @@ -675,6 +675,7 @@ WEBRTC_RTCSTATS_IMPL( &target_bitrate, &frames_encoded, &total_encode_time, + &total_packet_send_delay, &content_type) // clang-format on @@ -692,6 +693,7 @@ RTCOutboundRTPStreamStats::RTCOutboundRTPStreamStats(std::string&& id, target_bitrate("targetBitrate"), frames_encoded("framesEncoded"), total_encode_time("totalEncodeTime"), + total_packet_send_delay("totalPacketSendDelay"), content_type("contentType") {} RTCOutboundRTPStreamStats::RTCOutboundRTPStreamStats( @@ -704,6 +706,7 @@ RTCOutboundRTPStreamStats::RTCOutboundRTPStreamStats( target_bitrate(other.target_bitrate), frames_encoded(other.frames_encoded), total_encode_time(other.total_encode_time), + total_packet_send_delay(other.total_packet_send_delay), content_type(other.content_type) {} RTCOutboundRTPStreamStats::~RTCOutboundRTPStreamStats() {} diff --git a/video/send_statistics_proxy.cc b/video/send_statistics_proxy.cc index 638bb64f63..c504e828ee 100644 --- a/video/send_statistics_proxy.cc +++ b/video/send_statistics_proxy.cc @@ -1184,6 +1184,7 @@ void SendStatisticsProxy::FrameCountUpdated(const FrameCounts& frame_counts, void SendStatisticsProxy::SendSideDelayUpdated(int avg_delay_ms, int max_delay_ms, + uint64_t total_delay_ms, uint32_t ssrc) { rtc::CritScope lock(&crit_); VideoSendStream::StreamStats* stats = GetStatsEntry(ssrc); @@ -1191,6 +1192,7 @@ void SendStatisticsProxy::SendSideDelayUpdated(int avg_delay_ms, return; stats->avg_delay_ms = avg_delay_ms; stats->max_delay_ms = max_delay_ms; + stats->total_packet_send_delay_ms = total_delay_ms; uma_container_->delay_counter_.Add(avg_delay_ms); uma_container_->max_delay_counter_.Add(max_delay_ms); diff --git a/video/send_statistics_proxy.h b/video/send_statistics_proxy.h index ca8f542368..3b61f324c4 100644 --- a/video/send_statistics_proxy.h +++ b/video/send_statistics_proxy.h @@ -112,6 +112,7 @@ class SendStatisticsProxy : public VideoStreamEncoderObserver, void SendSideDelayUpdated(int avg_delay_ms, int max_delay_ms, + uint64_t total_delay_ms, uint32_t ssrc) override; private: diff --git a/video/send_statistics_proxy_unittest.cc b/video/send_statistics_proxy_unittest.cc index ded7fedc5e..08c1230a8b 100644 --- a/video/send_statistics_proxy_unittest.cc +++ b/video/send_statistics_proxy_unittest.cc @@ -290,18 +290,26 @@ TEST_F(SendStatisticsProxyTest, SendSideDelay) { // stream. int avg_delay_ms = ssrc; int max_delay_ms = ssrc + 1; - observer->SendSideDelayUpdated(avg_delay_ms, max_delay_ms, ssrc); + uint64_t total_packet_send_delay_ms = ssrc + 2; + observer->SendSideDelayUpdated(avg_delay_ms, max_delay_ms, + total_packet_send_delay_ms, ssrc); expected_.substreams[ssrc].avg_delay_ms = avg_delay_ms; expected_.substreams[ssrc].max_delay_ms = max_delay_ms; + expected_.substreams[ssrc].total_packet_send_delay_ms = + total_packet_send_delay_ms; } for (const auto& ssrc : config_.rtp.rtx.ssrcs) { // Use ssrc as avg_delay_ms and max_delay_ms to get a unique value for each // stream. int avg_delay_ms = ssrc; int max_delay_ms = ssrc + 1; - observer->SendSideDelayUpdated(avg_delay_ms, max_delay_ms, ssrc); + uint64_t total_packet_send_delay_ms = ssrc + 2; + observer->SendSideDelayUpdated(avg_delay_ms, max_delay_ms, + total_packet_send_delay_ms, ssrc); expected_.substreams[ssrc].avg_delay_ms = avg_delay_ms; expected_.substreams[ssrc].max_delay_ms = max_delay_ms; + expected_.substreams[ssrc].total_packet_send_delay_ms = + total_packet_send_delay_ms; } VideoSendStream::Stats stats = statistics_proxy_->GetStats(); ExpectEqual(expected_, stats);