From d08d389ce836238030ec31e45c5f9a5535e0855f Mon Sep 17 00:00:00 2001 From: "asapersson@webrtc.org" Date: Tue, 16 Dec 2014 12:03:11 +0000 Subject: [PATCH] Add field to counters for when first rtp/rtcp packet is sent/received. Use this time for histogram statistics (send/receive bitrates, sent/received rtcp fir/nack packets/min). BUG=crbug/419657 R=mflodman@webrtc.org, stefan@webrtc.org Review URL: https://webrtc-codereview.appspot.com/32219004 git-svn-id: http://webrtc.googlecode.com/svn/trunk@7910 4adac7df-926f-26a2-2b94-8c16560cd09d --- webrtc/common_types.h | 56 ++++++++--- .../source/receive_statistics_impl.cc | 1 + .../source/receive_statistics_unittest.cc | 8 +- .../modules/rtp_rtcp/source/rtcp_receiver.cc | 4 + webrtc/modules/rtp_rtcp/source/rtcp_sender.cc | 4 + .../rtp_rtcp/source/rtp_rtcp_impl_unittest.cc | 45 +++++++++ webrtc/modules/rtp_rtcp/source/rtp_sender.cc | 3 + .../rtp_rtcp/source/rtp_sender_unittest.cc | 1 + webrtc/video_engine/vie_channel.cc | 97 ++++++++++--------- webrtc/video_engine/vie_channel.h | 2 - 10 files changed, 154 insertions(+), 67 deletions(-) diff --git a/webrtc/common_types.h b/webrtc/common_types.h index 43d1bd706..e647aadd3 100644 --- a/webrtc/common_types.h +++ b/webrtc/common_types.h @@ -200,7 +200,8 @@ class RtcpStatisticsCallback { // Statistics for RTCP packet types. struct RtcpPacketTypeCounter { RtcpPacketTypeCounter() - : nack_packets(0), + : first_packet_time_ms(-1), + nack_packets(0), fir_packets(0), pli_packets(0), nack_requests(0), @@ -212,6 +213,16 @@ struct RtcpPacketTypeCounter { pli_packets += other.pli_packets; nack_requests += other.nack_requests; unique_nack_requests += other.unique_nack_requests; + if (other.first_packet_time_ms != -1 && + (other.first_packet_time_ms < first_packet_time_ms || + first_packet_time_ms == -1)) { + // Use oldest time. + first_packet_time_ms = other.first_packet_time_ms; + } + } + + int64_t TimeSinceFirstPacketInMs(int64_t now_ms) const { + return (first_packet_time_ms == -1) ? -1 : (now_ms - first_packet_time_ms); } int UniqueNackRequestsInPercent() const { @@ -222,25 +233,27 @@ struct RtcpPacketTypeCounter { (unique_nack_requests * 100.0f / nack_requests) + 0.5f); } - uint32_t nack_packets; // Number of RTCP NACK packets. - uint32_t fir_packets; // Number of RTCP FIR packets. - uint32_t pli_packets; // Number of RTCP PLI packets. - uint32_t nack_requests; // Number of NACKed RTP packets. + int64_t first_packet_time_ms; // Time when first packet is sent/received. + uint32_t nack_packets; // Number of RTCP NACK packets. + uint32_t fir_packets; // Number of RTCP FIR packets. + uint32_t pli_packets; // Number of RTCP PLI packets. + uint32_t nack_requests; // Number of NACKed RTP packets. uint32_t unique_nack_requests; // Number of unique NACKed RTP packets. }; // Data usage statistics for a (rtp) stream. struct StreamDataCounters { StreamDataCounters() - : bytes(0), - header_bytes(0), - padding_bytes(0), - packets(0), - retransmitted_bytes(0), - retransmitted_header_bytes(0), - retransmitted_padding_bytes(0), - retransmitted_packets(0), - fec_packets(0) {} + : first_packet_time_ms(-1), + bytes(0), + header_bytes(0), + padding_bytes(0), + packets(0), + retransmitted_bytes(0), + retransmitted_header_bytes(0), + retransmitted_padding_bytes(0), + retransmitted_packets(0), + fec_packets(0) {} void Add(const StreamDataCounters& other) { bytes += other.bytes; @@ -252,6 +265,16 @@ struct StreamDataCounters { retransmitted_padding_bytes += other.retransmitted_padding_bytes; retransmitted_packets += other.retransmitted_packets; fec_packets += other.fec_packets; + if (other.first_packet_time_ms != -1 && + (other.first_packet_time_ms < first_packet_time_ms || + first_packet_time_ms == -1)) { + // Use oldest time. + first_packet_time_ms = other.first_packet_time_ms; + } + } + + int64_t TimeSinceFirstPacketInMs(int64_t now_ms) const { + return (first_packet_time_ms == -1) ? -1 : (now_ms - first_packet_time_ms); } size_t TotalBytes() const { @@ -268,6 +291,7 @@ struct StreamDataCounters { } // TODO(pbos): Rename bytes -> media_bytes. + int64_t first_packet_time_ms; // Time when first packet is sent/received. size_t bytes; // Payload bytes, excluding RTP headers and padding. size_t header_bytes; // Number of bytes used by RTP headers. size_t padding_bytes; // Number of padding bytes. @@ -288,7 +312,7 @@ class StreamDataCountersCallback { uint32_t ssrc) = 0; }; -// Rate statistics for a stream +// Rate statistics for a stream. struct BitrateStatistics { BitrateStatistics() : bitrate_bps(0), packet_rate(0), timestamp_ms(0) {} @@ -307,7 +331,7 @@ class BitrateStatisticsObserver { uint32_t ssrc) = 0; }; -// Callback, used to notify an observer whenever frame counts have been updated +// Callback, used to notify an observer whenever frame counts have been updated. class FrameCountObserver { public: virtual ~FrameCountObserver() {} diff --git a/webrtc/modules/rtp_rtcp/source/receive_statistics_impl.cc b/webrtc/modules/rtp_rtcp/source/receive_statistics_impl.cc index 321ea132c..7ba83f7c9 100644 --- a/webrtc/modules/rtp_rtcp/source/receive_statistics_impl.cc +++ b/webrtc/modules/rtp_rtcp/source/receive_statistics_impl.cc @@ -96,6 +96,7 @@ void StreamStatisticianImpl::UpdateCounters(const RTPHeader& header, if (receive_counters_.packets == 1) { received_seq_first_ = header.sequenceNumber; + receive_counters_.first_packet_time_ms = clock_->TimeInMilliseconds(); } // Count only the new packets received. That is, if packets 1, 2, 3, 5, 4, 6 diff --git a/webrtc/modules/rtp_rtcp/source/receive_statistics_unittest.cc b/webrtc/modules/rtp_rtcp/source/receive_statistics_unittest.cc index 6cc60089f..93351e53b 100644 --- a/webrtc/modules/rtp_rtcp/source/receive_statistics_unittest.cc +++ b/webrtc/modules/rtp_rtcp/source/receive_statistics_unittest.cc @@ -140,12 +140,18 @@ TEST_F(ReceiveStatisticsTest, GetReceiveStreamDataCounters) { StreamDataCounters counters; statistician->GetReceiveStreamDataCounters(&counters); + EXPECT_GT(counters.first_packet_time_ms, -1); EXPECT_EQ(1u, counters.packets); - // GetReceiveStreamDataCounters includes reset counter values. statistician->ResetStatistics(); + // GetReceiveStreamDataCounters includes reset counter values. + statistician->GetReceiveStreamDataCounters(&counters); + EXPECT_GT(counters.first_packet_time_ms, -1); + EXPECT_EQ(1u, counters.packets); + receive_statistics_->IncomingPacket(header1_, kPacketSize1, false); statistician->GetReceiveStreamDataCounters(&counters); + EXPECT_GT(counters.first_packet_time_ms, -1); EXPECT_EQ(2u, counters.packets); } diff --git a/webrtc/modules/rtp_rtcp/source/rtcp_receiver.cc b/webrtc/modules/rtp_rtcp/source/rtcp_receiver.cc index 8d044801f..814937017 100644 --- a/webrtc/modules/rtp_rtcp/source/rtcp_receiver.cc +++ b/webrtc/modules/rtp_rtcp/source/rtcp_receiver.cc @@ -316,6 +316,10 @@ RTCPReceiver::IncomingRTCPPacket(RTCPPacketInformation& rtcpPacketInformation, _lastReceived = _clock->TimeInMilliseconds(); + if (packet_type_counter_.first_packet_time_ms == -1) { + packet_type_counter_.first_packet_time_ms = _lastReceived; + } + RTCPUtility::RTCPPacketTypes pktType = rtcpParser->Begin(); while (pktType != RTCPUtility::kRtcpNotValidCode) { diff --git a/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc b/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc index 3386d9b5f..e060c8c9f 100644 --- a/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc +++ b/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc @@ -1632,6 +1632,10 @@ int RTCPSender::PrepareRTCP(const FeedbackState& feedback_state, CriticalSectionScoped lock(_criticalSectionRTCPSender); + if (packet_type_counter_.first_packet_time_ms == -1) { + packet_type_counter_.first_packet_time_ms = _clock->TimeInMilliseconds(); + } + if(_TMMBR ) // Attach TMMBR to send and receive reports. { rtcpPacketTypeFlags |= kRtcpTmmbr; diff --git a/webrtc/modules/rtp_rtcp/source/rtp_rtcp_impl_unittest.cc b/webrtc/modules/rtp_rtcp/source/rtp_rtcp_impl_unittest.cc index d6e025234..f1d060462 100644 --- a/webrtc/modules/rtp_rtcp/source/rtp_rtcp_impl_unittest.cc +++ b/webrtc/modules/rtp_rtcp/source/rtp_rtcp_impl_unittest.cc @@ -325,16 +325,21 @@ TEST_F(RtpRtcpImplTest, RttForReceiverOnly) { } TEST_F(RtpRtcpImplTest, RtcpPacketTypeCounter_Nack) { + EXPECT_EQ(-1, receiver_.RtcpSent().first_packet_time_ms); + EXPECT_EQ(-1, sender_.RtcpReceived().first_packet_time_ms); EXPECT_EQ(0U, sender_.RtcpReceived().nack_packets); EXPECT_EQ(0U, receiver_.RtcpSent().nack_packets); + // Receive module sends a NACK. const uint16_t kNackLength = 1; uint16_t nack_list[kNackLength] = {123}; EXPECT_EQ(0, receiver_.impl_->SendNACK(nack_list, kNackLength)); EXPECT_EQ(1U, receiver_.RtcpSent().nack_packets); + EXPECT_GT(receiver_.RtcpSent().first_packet_time_ms, -1); // Send module receives the NACK. EXPECT_EQ(1U, sender_.RtcpReceived().nack_packets); + EXPECT_GT(sender_.RtcpReceived().first_packet_time_ms, -1); } TEST_F(RtpRtcpImplTest, RtcpPacketTypeCounter_FirAndPli) { @@ -355,6 +360,46 @@ TEST_F(RtpRtcpImplTest, RtcpPacketTypeCounter_FirAndPli) { EXPECT_EQ(1U, sender_.RtcpReceived().pli_packets); } +TEST_F(RtpRtcpImplTest, AddStreamDataCounters) { + StreamDataCounters rtp; + const int64_t kStartTimeMs = 1; + rtp.first_packet_time_ms = kStartTimeMs; + rtp.packets = 1; + rtp.bytes = 1; + rtp.header_bytes = 2; + rtp.padding_bytes = 3; + EXPECT_EQ(rtp.TotalBytes(), rtp.bytes + rtp.header_bytes + rtp.padding_bytes); + + StreamDataCounters rtp2; + rtp2.first_packet_time_ms = -1; + rtp2.packets = 10; + rtp2.bytes = 10; + rtp2.retransmitted_header_bytes = 4; + rtp2.retransmitted_bytes = 5; + rtp2.retransmitted_padding_bytes = 6; + rtp2.retransmitted_packets = 7; + rtp2.fec_packets = 8; + + StreamDataCounters sum = rtp; + sum.Add(rtp2); + EXPECT_EQ(kStartTimeMs, sum.first_packet_time_ms); + EXPECT_EQ(11U, sum.packets); + EXPECT_EQ(11U, sum.bytes); + EXPECT_EQ(2U, sum.header_bytes); + EXPECT_EQ(3U, sum.padding_bytes); + EXPECT_EQ(4U, sum.retransmitted_header_bytes); + EXPECT_EQ(5U, sum.retransmitted_bytes); + EXPECT_EQ(6U, sum.retransmitted_padding_bytes); + EXPECT_EQ(7U, sum.retransmitted_packets); + EXPECT_EQ(8U, sum.fec_packets); + EXPECT_EQ(sum.TotalBytes(), rtp.TotalBytes() + rtp2.TotalBytes()); + + StreamDataCounters rtp3; + rtp3.first_packet_time_ms = kStartTimeMs + 10; + sum.Add(rtp3); + EXPECT_EQ(kStartTimeMs, sum.first_packet_time_ms); // Holds oldest time. +} + TEST_F(RtpRtcpImplTest, SendsInitialNackList) { // Send module sends a NACK. const uint16_t kNackLength = 1; diff --git a/webrtc/modules/rtp_rtcp/source/rtp_sender.cc b/webrtc/modules/rtp_rtcp/source/rtp_sender.cc index 7c4307f01..3d2dfbe08 100644 --- a/webrtc/modules/rtp_rtcp/source/rtp_sender.cc +++ b/webrtc/modules/rtp_rtcp/source/rtp_sender.cc @@ -907,6 +907,9 @@ void RTPSender::UpdateRtpStats(const uint8_t* buffer, total_bitrate_sent_.Update(packet_length); ++counters->packets; + if (counters->packets == 1) { + counters->first_packet_time_ms = clock_->TimeInMilliseconds(); + } if (IsFecPacket(buffer, header)) { ++counters->fec_packets; } diff --git a/webrtc/modules/rtp_rtcp/source/rtp_sender_unittest.cc b/webrtc/modules/rtp_rtcp/source/rtp_sender_unittest.cc index 866258be7..253d1b997 100644 --- a/webrtc/modules/rtp_rtcp/source/rtp_sender_unittest.cc +++ b/webrtc/modules/rtp_rtcp/source/rtp_sender_unittest.cc @@ -1162,6 +1162,7 @@ TEST_F(RtpSenderTest, BytesReportedCorrectly) { rtp_sender_->GetDataCounters(&rtp_stats, &rtx_stats); // Payload + 1-byte generic header. + EXPECT_GT(rtp_stats.first_packet_time_ms, -1); EXPECT_EQ(rtp_stats.bytes, sizeof(payload) + 1); EXPECT_EQ(rtp_stats.header_bytes, 12u); EXPECT_EQ(rtp_stats.padding_bytes, 0u); diff --git a/webrtc/video_engine/vie_channel.cc b/webrtc/video_engine/vie_channel.cc index be6a2d137..fffb970cf 100644 --- a/webrtc/video_engine/vie_channel.cc +++ b/webrtc/video_engine/vie_channel.cc @@ -147,9 +147,7 @@ ViEChannel::ViEChannel(int32_t channel_id, sender_(sender), nack_history_size_sender_(kSendSidePacketHistorySize), max_nack_reordering_threshold_(kMaxPacketAgeToNack), - pre_render_callback_(NULL), - start_ms_(Clock::GetRealTimeClock()->TimeInMilliseconds()), - start_send_ms_(0) { + pre_render_callback_(NULL) { RtpRtcp::Configuration configuration = CreateRtpRtcpConfiguration(); configuration.remote_bitrate_estimator = remote_bitrate_estimator; configuration.receive_statistics = vie_receiver_.GetReceiveStatistics(); @@ -237,76 +235,80 @@ ViEChannel::~ViEChannel() { } void ViEChannel::UpdateHistograms() { - // TODO(asapersson): Use time from first sent/received packet. - float elapsed_minutes = - (Clock::GetRealTimeClock()->TimeInMilliseconds() - start_ms_) / 60000.0f; - if (elapsed_minutes < metrics::kMinRunTimeInSeconds / 60.0f) { - return; - } + int64_t now = Clock::GetRealTimeClock()->TimeInMilliseconds(); RtcpPacketTypeCounter rtcp_sent; RtcpPacketTypeCounter rtcp_received; GetRtcpPacketTypeCounters(&rtcp_sent, &rtcp_received); if (sender_) { - if (rtcp_received.nack_requests > 0) { - RTC_HISTOGRAM_PERCENTAGE( - "WebRTC.Video.UniqueNackRequestsReceivedInPercent", - rtcp_received.UniqueNackRequestsInPercent()); + int64_t elapsed_sec = rtcp_received.TimeSinceFirstPacketInMs(now) / 1000; + if (elapsed_sec > metrics::kMinRunTimeInSeconds) { + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.NackPacketsReceivedPerMinute", + rtcp_received.nack_packets / elapsed_sec / 60); + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.FirPacketsReceivedPerMinute", + rtcp_received.fir_packets / elapsed_sec / 60); + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.PliPacketsReceivedPerMinute", + rtcp_received.pli_packets / elapsed_sec / 60); + if (rtcp_received.nack_requests > 0) { + RTC_HISTOGRAM_PERCENTAGE( + "WebRTC.Video.UniqueNackRequestsReceivedInPercent", + rtcp_received.UniqueNackRequestsInPercent()); + } } - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.NackPacketsReceivedPerMinute", - rtcp_received.nack_packets / elapsed_minutes); - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.FirPacketsReceivedPerMinute", - rtcp_received.fir_packets / elapsed_minutes); - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.PliPacketsReceivedPerMinute", - rtcp_received.pli_packets / elapsed_minutes); } else if (vie_receiver_.GetRemoteSsrc() > 0) { // Get receive stats if we are receiving packets, i.e. there is a remote // ssrc. - if (rtcp_sent.nack_requests > 0) { - RTC_HISTOGRAM_PERCENTAGE("WebRTC.Video.UniqueNackRequestsSentInPercent", - rtcp_sent.UniqueNackRequestsInPercent()); + int64_t elapsed_sec = rtcp_sent.TimeSinceFirstPacketInMs(now) / 1000; + if (elapsed_sec > metrics::kMinRunTimeInSeconds) { + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.NackPacketsSentPerMinute", + rtcp_sent.nack_packets / elapsed_sec / 60); + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.FirPacketsSentPerMinute", + rtcp_sent.fir_packets / elapsed_sec / 60); + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.PliPacketsSentPerMinute", + rtcp_sent.pli_packets / elapsed_sec / 60); + if (rtcp_sent.nack_requests > 0) { + RTC_HISTOGRAM_PERCENTAGE("WebRTC.Video.UniqueNackRequestsSentInPercent", + rtcp_sent.UniqueNackRequestsInPercent()); + } } - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.NackPacketsSentPerMinute", - rtcp_sent.nack_packets / elapsed_minutes); - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.FirPacketsSentPerMinute", - rtcp_sent.fir_packets / elapsed_minutes); - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.PliPacketsSentPerMinute", - rtcp_sent.pli_packets / elapsed_minutes); StreamDataCounters rtp; StreamDataCounters rtx; GetReceiveStreamDataCounters(&rtp, &rtx); StreamDataCounters rtp_rtx = rtp; rtp_rtx.Add(rtx); - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.BitrateReceivedInKbps", - rtp_rtx.TotalBytes() * 8 / (elapsed_minutes * 60) / 1000); - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.MediaBitrateReceivedInKbps", - rtp.MediaPayloadBytes() * 8 / (elapsed_minutes * 60) / 1000); - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.PaddingBitrateReceivedInKbps", - rtp_rtx.padding_bytes * 8 / (elapsed_minutes * 60) / 1000); - RTC_HISTOGRAM_COUNTS_10000( - "WebRTC.Video.RetransmittedBitrateReceivedInKbps", - rtp_rtx.RetransmittedBytes() * 8 / (elapsed_minutes * 60) / 1000); - uint32_t ssrc = 0; - if (vie_receiver_.GetRtxSsrc(&ssrc)) { - RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.RtxBitrateReceivedInKbps", - rtx.TotalBytes() * 8 / (elapsed_minutes * 60) / 1000); + elapsed_sec = rtp_rtx.TimeSinceFirstPacketInMs(now) / 1000; + if (elapsed_sec > metrics::kMinRunTimeInSeconds) { + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.BitrateReceivedInKbps", + rtp_rtx.TotalBytes() * 8 / elapsed_sec / 1000); + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.MediaBitrateReceivedInKbps", + rtp.MediaPayloadBytes() * 8 / elapsed_sec / 1000); + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.PaddingBitrateReceivedInKbps", + rtp_rtx.padding_bytes * 8 / elapsed_sec / 1000); + RTC_HISTOGRAM_COUNTS_10000( + "WebRTC.Video.RetransmittedBitrateReceivedInKbps", + rtp_rtx.RetransmittedBytes() * 8 / elapsed_sec / 1000); + uint32_t ssrc = 0; + if (vie_receiver_.GetRtxSsrc(&ssrc)) { + RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.RtxBitrateReceivedInKbps", + rtx.TotalBytes() * 8 / elapsed_sec / 1000); + } } } } void ViEChannel::UpdateHistogramsAtStopSend() { - // TODO(asapersson): Use time from first sent packet. - int64_t elapsed_sec = - (Clock::GetRealTimeClock()->TimeInMilliseconds() - start_send_ms_) / 1000; - if (elapsed_sec < metrics::kMinRunTimeInSeconds) { - return; - } StreamDataCounters rtp; StreamDataCounters rtx; GetSendStreamDataCounters(&rtp, &rtx); StreamDataCounters rtp_rtx = rtp; rtp_rtx.Add(rtx); + + int64_t elapsed_sec = rtp_rtx.TimeSinceFirstPacketInMs( + Clock::GetRealTimeClock()->TimeInMilliseconds()) / 1000; + if (elapsed_sec < metrics::kMinRunTimeInSeconds) { + return; + } RTC_HISTOGRAM_COUNTS_100000("WebRTC.Video.BitrateSentInKbps", rtp_rtx.TotalBytes() * 8 / elapsed_sec / 1000); RTC_HISTOGRAM_COUNTS_10000("WebRTC.Video.MediaBitrateSentInKbps", @@ -1393,7 +1395,6 @@ int32_t ViEChannel::StartSend() { rtp_rtcp->SetSendingMediaStatus(true); rtp_rtcp->SetSendingStatus(true); } - start_send_ms_ = Clock::GetRealTimeClock()->TimeInMilliseconds(); return 0; } diff --git a/webrtc/video_engine/vie_channel.h b/webrtc/video_engine/vie_channel.h index 88d4a9486..b97835351 100644 --- a/webrtc/video_engine/vie_channel.h +++ b/webrtc/video_engine/vie_channel.h @@ -502,8 +502,6 @@ class ViEChannel int nack_history_size_sender_; int max_nack_reordering_threshold_; I420FrameCallback* pre_render_callback_; - const int64_t start_ms_; - int64_t start_send_ms_; std::map prev_report_blocks_; };