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
diff --git a/webrtc/common_types.h b/webrtc/common_types.h
index 43d1bd7..e647aad 100644
--- a/webrtc/common_types.h
+++ b/webrtc/common_types.h
@@ -200,7 +200,8 @@
 // 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 @@
     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 @@
         (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 @@
     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 @@
   }
 
   // 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 @@
                                    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 @@
                       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 321ea13..7ba83f7 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 @@
 
   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 6cc6008..93351e5 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 @@
 
   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 8d04480..8149370 100644
--- a/webrtc/modules/rtp_rtcp/source/rtcp_receiver.cc
+++ b/webrtc/modules/rtp_rtcp/source/rtcp_receiver.cc
@@ -316,6 +316,10 @@
 
     _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 3386d9b..e060c8c 100644
--- a/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc
+++ b/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc
@@ -1632,6 +1632,10 @@
 
   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 d6e0252..f1d0604 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, 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 @@
   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 7c4307f..3d2dfbe 100644
--- a/webrtc/modules/rtp_rtcp/source/rtp_sender.cc
+++ b/webrtc/modules/rtp_rtcp/source/rtp_sender.cc
@@ -907,6 +907,9 @@
 
   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 866258b..253d1b9 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 @@
   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 be6a2d1..fffb970 100644
--- a/webrtc/video_engine/vie_channel.cc
+++ b/webrtc/video_engine/vie_channel.cc
@@ -147,9 +147,7 @@
       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 @@
 }
 
 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 @@
     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 88d4a94..b978353 100644
--- a/webrtc/video_engine/vie_channel.h
+++ b/webrtc/video_engine/vie_channel.h
@@ -502,8 +502,6 @@
   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<uint32_t, RTCPReportBlock> prev_report_blocks_;
 };