Add histogram stats for send delay for a sent video stream.

webrtc/video/send_statistics_proxy.cc

 /*
  *  Copyright (c) 2013 The WebRTC project authors. All Rights Reserved.
  *
  *  Use of this source code is governed by a BSD-style license
  *  that can be found in the LICENSE file in the root of the source
  *  tree. An additional intellectual property rights grant can be found
  *  in the file PATENTS.  All contributing project authors may
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
 #include "webrtc/video/send_statistics_proxy.h"
 
 #include <algorithm>
 #include <cmath>
 #include <map>
 #include <vector>
 
 #include "webrtc/base/checks.h"
 #include "webrtc/base/logging.h"
 #include "webrtc/system_wrappers/include/metrics.h"
 
 namespace webrtc {
 namespace {
 const float kEncodeTimeWeigthFactor = 0.5f;
 
+// Packet with a larger delay are removed and excluded from the delay stats.
+// Set to larger than max histogram delay which is 10000.
+const int64_t kMaxSentPacketDelayMs = 11000;
+const size_t kMaxSendPacketMapSize = 2000;
+
 // Used by histograms. Values of entries should not be changed.
 enum HistogramCodecType {
   kVideoUnknown = 0,
   kVideoVp8 = 1,
   kVideoVp9 = 2,
   kVideoH264 = 3,
   kVideoMax = 64,
 };
 
 const char* kRealtimePrefix = "WebRTC.Video.";
@@ skipping 35 matching lines @@
 
 SendStatisticsProxy::SendStatisticsProxy(
     Clock* clock,
     const VideoSendStream::Config& config,
     VideoEncoderConfig::ContentType content_type)
     : clock_(clock),
       config_(config),
       content_type_(content_type),
       last_sent_frame_timestamp_(0),
       encode_time_(kEncodeTimeWeigthFactor),
+      num_old_packets_(0),
+      num_skipped_packets_(0),
       uma_container_(
           new UmaSamplesContainer(GetUmaPrefix(content_type_), stats_, clock)) {
   UpdateCodecTypeHistogram(config_.encoder_settings.payload_name);
 }
 
 SendStatisticsProxy::~SendStatisticsProxy() {
+  if (num_old_packets_ > 0 || num_skipped_packets_ > 0) {
+    LOG(LS_WARNING) << "Delay stats: number of old packets " << num_old_packets_
+                    << ", skipped packets " << num_skipped_packets_;
+  }
   rtc::CritScope lock(&crit_);
   uma_container_->UpdateHistograms(config_, stats_);
 }
 
 SendStatisticsProxy::UmaSamplesContainer::UmaSamplesContainer(
     const char* prefix,
     const VideoSendStream::Stats& stats,
     Clock* const clock)
     : uma_prefix_(prefix),
       clock_(clock),
@@ skipping 88 matching lines @@
   int delay_ms = delay_counter_.Avg(kMinRequiredSamples);
   if (delay_ms != -1)
     RTC_LOGGED_HISTOGRAMS_COUNTS_100000(
         kIndex, uma_prefix_ + "SendSideDelayInMs", delay_ms);
 
   int max_delay_ms = max_delay_counter_.Avg(kMinRequiredSamples);
   if (max_delay_ms != -1) {
     RTC_LOGGED_HISTOGRAMS_COUNTS_100000(
         kIndex, uma_prefix_ + "SendSideDelayMaxInMs", max_delay_ms);
   }
+  for (const auto& it : send_delay_counters_) {
+    int send_delay_ms = it.second.Avg(kMinRequiredSamples);
+    if (send_delay_ms != -1) {
+      RTC_LOGGED_HISTOGRAMS_COUNTS_10000(kIndex, uma_prefix_ + "SendDelayInMs",
+                                         send_delay_ms);
+    }
+  }
 
   for (const auto& it : qp_counters_) {
     int qp_vp8 = it.second.vp8.Avg(kMinRequiredSamples);
     if (qp_vp8 != -1) {
       int spatial_idx = it.first;
       if (spatial_idx == -1) {
         RTC_LOGGED_HISTOGRAMS_COUNTS_200(kIndex, uma_prefix_ + "Encoded.Qp.Vp8",
                                          qp_vp8);
       } else if (spatial_idx == 0) {
         RTC_LOGGED_HISTOGRAMS_COUNTS_200(
@@ skipping 376 matching lines @@
   VideoSendStream::StreamStats* stats = GetStatsEntry(ssrc);
   if (!stats)
     return;
   stats->avg_delay_ms = avg_delay_ms;
   stats->max_delay_ms = max_delay_ms;
 
   uma_container_->delay_counter_.Add(avg_delay_ms);
   uma_container_->max_delay_counter_.Add(max_delay_ms);
 }
 
+void SendStatisticsProxy::OnSendPacket(uint16_t packet_id,
+                                       int64_t capture_time_ms,
+                                       uint32_t ssrc) {
+  // Packet sent to transport.
+  rtc::CritScope lock(&crit_);
+  if (GetStatsEntry(ssrc) == nullptr)
+    return;
+
+  int64_t now = clock_->TimeInMilliseconds();
+  RemoveOld(now, &packets_);
+
+  if (packets_.size() > kMaxSendPacketMapSize) {
+    ++num_skipped_packets_;
+    return;
+  }
+  packets_.insert(
+      std::make_pair(packet_id, Packet(ssrc, capture_time_ms, now)));
+}
+
+bool SendStatisticsProxy::OnSentPacket(int packet_id) {
+  // Packet leaving socket.
+  if (packet_id == -1)
+    return false;
+
+  rtc::CritScope lock(&crit_);
+  auto it = packets_.find(packet_id);
+  if (it == packets_.end())
+    return false;
+
+  // TODO(asapersson): Remove SendSideDelayUpdated(), use capture -> sent.
+  // Elapsed time from send (to transport) -> sent (leaving socket).
+  int diff_ms = clock_->TimeInMilliseconds() - it->second.send_time_ms;

[mflodman, 2016/04/26 06:49:11]

Is there some way we could get this time when actually sent on the socket or
doesn't that work due to clock differences?

Anything else we can do to get this time as early as possible?

[åsapersson, 2016/04/28 12:26:19]

Right, it is not working due to clock differences. Changed so the time is got a
bit earlier, in Call for now.

+  uma_container_->send_delay_counters_[it->second.ssrc].Add(diff_ms);
+  packets_.erase(it);
+  return true;
+}
+
+void SendStatisticsProxy::RemoveOld(int64_t now, PacketMap* packets) {
+  while (!packets->empty()) {
+    auto it = packets->begin();
+    if (now - it->second.capture_time_ms < kMaxSentPacketDelayMs)
+      break;
+
+    packets->erase(it);
+    ++num_old_packets_;
+  }
+}
+
 void SendStatisticsProxy::SampleCounter::Add(int sample) {
   sum += sample;
   ++num_samples;
 }
 
 int SendStatisticsProxy::SampleCounter::Avg(int min_required_samples) const {
   if (num_samples < min_required_samples || num_samples == 0)
     return -1;
   return (sum + (num_samples / 2)) / num_samples;
 }
@@ skipping 14 matching lines @@
   return Fraction(min_required_samples, 1000.0f);
 }
 
 int SendStatisticsProxy::BoolSampleCounter::Fraction(
     int min_required_samples, float multiplier) const {
   if (num_samples < min_required_samples || num_samples == 0)
     return -1;
   return static_cast<int>((sum * multiplier / num_samples) + 0.5f);
 }
 }  // namespace webrtc