Add traces for some video events.

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/base/trace_event.h"
 #include "webrtc/modules/video_coding/include/video_codec_interface.h"
 #include "webrtc/system_wrappers/include/metrics.h"
 
 namespace webrtc {
 namespace {
 const float kEncodeTimeWeigthFactor = 0.5f;
 
 // Used by histograms. Values of entries should not be changed.
 enum HistogramCodecType {
   kVideoUnknown = 0,
@@ skipping 389 matching lines @@
         GetUmaPrefix(config.content_type), stats_, clock_));
     content_type_ = config.content_type;
   }
 }
 
 void SendStatisticsProxy::OnEncoderStatsUpdate(uint32_t framerate,
                                                uint32_t bitrate) {
   rtc::CritScope lock(&crit_);
   stats_.encode_frame_rate = framerate;
   stats_.media_bitrate_bps = bitrate;
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::FrameRateSent",

[tommi, 2017/03/15 13:49:08]

nit: since WebRTC::Video::FrameRateSent does not map to C++ code, I would rather
name this something like "WebRTC.Video.FrameRateSent".  Even the "WebRTC." part
might be too much since it's already in the category.

Same for other names.

[ehmaldonado_webrtc, 2017/03/15 15:29:33]

Done. I decided to leave the WebRTC in so it has the same name as the
histograms.

+      "frame_rate", framerate, "ssrc", rtp_config_.ssrcs[0]);
 }
 
 void SendStatisticsProxy::OnEncodedFrameTimeMeasured(
     int encode_time_ms,
     const CpuOveruseMetrics& metrics) {
   rtc::CritScope lock(&crit_);
   uma_container_->encode_time_counter_.Add(encode_time_ms);
   encode_time_.Apply(1.0f, encode_time_ms);
   stats_.avg_encode_time_ms = round(encode_time_.filtered());
   stats_.encode_usage_percent = metrics.encode_usage_percent;
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::EncodeTimeInMs",
+      "encode_time_ms", stats_.avg_encode_time_ms,
+      "ssrc", rtp_config_.ssrcs[0]);
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::EncodeUsagePercent",
+      "encode_usage_percent", stats_.encode_usage_percent,
+      "ssrc", rtp_config_.ssrcs[0]);
 }
 
 void SendStatisticsProxy::OnSuspendChange(bool is_suspended) {
   rtc::CritScope lock(&crit_);
   stats_.suspended = is_suspended;
   if (is_suspended) {
     // Pause framerate (add min pause time since there may be frames/packets
     // that are not yet sent).
     const int64_t kMinMs = 500;
     uma_container_->input_fps_counter_.ProcessAndPauseForDuration(kMinMs);
@@ skipping 123 matching lines @@
   uint32_t ssrc = rtp_config_.ssrcs[simulcast_idx];
 
   VideoSendStream::StreamStats* stats = GetStatsEntry(ssrc);
   if (!stats)
     return;
 
   stats->width = encoded_image._encodedWidth;
   stats->height = encoded_image._encodedHeight;
   update_times_[ssrc].resolution_update_ms = clock_->TimeInMilliseconds();
 
+  // Would it be better to report these at the end?
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::FrameHeightSent",
+      "frame_height", encoded_image._encodedHeight,
+      "ssrc", ssrc);
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::FrameWidthSent",
+      "frame_width", encoded_image._encodedWidth,
+      "ssrc", ssrc);
+
   uma_container_->key_frame_counter_.Add(encoded_image._frameType ==
                                          kVideoFrameKey);
   stats_.bw_limited_resolution =
       encoded_image.adapt_reason_.bw_resolutions_disabled > 0 ||
       quality_downscales_ > 0;
 
   if (quality_downscales_ != -1) {
     uma_container_->quality_limited_frame_counter_.Add(quality_downscales_ > 0);
     if (quality_downscales_ > 0)
       uma_container_->quality_downscales_counter_.Add(quality_downscales_);
@@ skipping 58 matching lines @@
   return stats_.encode_frame_rate;
 }
 
 void SendStatisticsProxy::OnIncomingFrame(int width, int height) {
   rtc::CritScope lock(&crit_);
   uma_container_->input_frame_rate_tracker_.AddSamples(1);
   uma_container_->input_fps_counter_.Add(1);
   uma_container_->input_width_counter_.Add(width);
   uma_container_->input_height_counter_.Add(height);
   uma_container_->cpu_limited_frame_counter_.Add(stats_.cpu_limited_resolution);
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::FrameRateInput",
+      "frame_rate", round(
+          uma_container_->input_frame_rate_tracker_.ComputeRate()),
+      "ssrc", rtp_config_.ssrcs[0]);
 }
 
 void SendStatisticsProxy::SetResolutionRestrictionStats(
     bool scaling_enabled,
     bool cpu_restricted,
     int num_quality_downscales) {
   rtc::CritScope lock(&crit_);
   if (scaling_enabled) {
     quality_downscales_ = num_quality_downscales;
     stats_.bw_limited_resolution = quality_downscales_ > 0;
     stats_.cpu_limited_resolution = cpu_restricted;
   } else {
     stats_.bw_limited_resolution = false;
     stats_.cpu_limited_resolution = false;
     quality_downscales_ = -1;
   }
 }
 
 void SendStatisticsProxy::OnCpuRestrictedResolutionChanged(
     bool cpu_restricted_resolution) {
   rtc::CritScope lock(&crit_);
   stats_.cpu_limited_resolution = cpu_restricted_resolution;
   ++stats_.number_of_cpu_adapt_changes;
+  TRACE_EVENT_INSTANT0("webrtc_stats", "WebRTC::Video::AdaptationChanges");
 }
 
 void SendStatisticsProxy::OnQualityRestrictedResolutionChanged(
     int num_quality_downscales) {
   rtc::CritScope lock(&crit_);
   quality_downscales_ = num_quality_downscales;
   stats_.bw_limited_resolution = quality_downscales_ > 0;
 }
 
 void SendStatisticsProxy::RtcpPacketTypesCounterUpdated(
     uint32_t ssrc,
     const RtcpPacketTypeCounter& packet_counter) {
   rtc::CritScope lock(&crit_);
   VideoSendStream::StreamStats* stats = GetStatsEntry(ssrc);
   if (!stats)
     return;
 
   stats->rtcp_packet_type_counts = packet_counter;
   if (uma_container_->first_rtcp_stats_time_ms_ == -1)
     uma_container_->first_rtcp_stats_time_ms_ = clock_->TimeInMilliseconds();
+
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::FirsReceived",
+      "fir_packets_received", packet_counter.fir_packets, "ssrc", ssrc);
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::NacksReceived",
+      "nack_packets_received", packet_counter.nack_packets, "ssrc", ssrc);
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::PlisReceived",
+      "pli_packets_received", packet_counter.pli_packets, "ssrc", ssrc);
 }
 
 void SendStatisticsProxy::StatisticsUpdated(const RtcpStatistics& statistics,
                                             uint32_t ssrc) {
   rtc::CritScope lock(&crit_);
   VideoSendStream::StreamStats* stats = GetStatsEntry(ssrc);
   if (!stats)
     return;
 
   stats->rtcp_stats = statistics;
   uma_container_->report_block_stats_.Store(statistics, 0, ssrc);
+
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::PacketsLost",
+      "packets_lost", statistics.cumulative_lost, "ssrc", ssrc);
 }
 
 void SendStatisticsProxy::CNameChanged(const char* cname, uint32_t ssrc) {}
 
 void SendStatisticsProxy::DataCountersUpdated(
     const StreamDataCounters& counters,
     uint32_t ssrc) {
   rtc::CritScope lock(&crit_);
   VideoSendStream::StreamStats* stats = GetStatsEntry(ssrc);
   RTC_DCHECK(stats) << "DataCountersUpdated reported for unknown ssrc " << ssrc;
@@ skipping 14 matching lines @@
                                             ssrc);
   uma_container_->retransmit_byte_counter_.Set(
       counters.retransmitted.TotalBytes(), ssrc);
   uma_container_->fec_byte_counter_.Set(counters.fec.TotalBytes(), ssrc);
   if (stats->is_rtx) {
     uma_container_->rtx_byte_counter_.Set(counters.transmitted.TotalBytes(),
                                           ssrc);
   } else {
     uma_container_->media_byte_counter_.Set(counters.MediaPayloadBytes(), ssrc);
   }
+
+  TRACE_EVENT_INSTANT2("webrtc_stats", "WebRTC::Video::PacketsSent",
+      "packets_sent", counters.transmitted.packets, "ssrc", ssrc);
 }
 
 void SendStatisticsProxy::Notify(uint32_t total_bitrate_bps,
                                  uint32_t retransmit_bitrate_bps,
                                  uint32_t ssrc) {
   rtc::CritScope lock(&crit_);
   VideoSendStream::StreamStats* stats = GetStatsEntry(ssrc);
   if (!stats)
     return;
 
@@ skipping 59 matching lines @@
 }
 
 int SendStatisticsProxy::BoolSampleCounter::Fraction(
     int64_t 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