Add periodic logging of video stats.

webrtc/media/engine/webrtcvideoengine2.cc

 /*
  *  Copyright (c) 2014 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.
  */
 
@@ skipping 324 matching lines @@
 // duration hasn't been implemented.
 static const int kNackHistoryMs = 1000;
 
 static const int kDefaultQpMax = 56;
 
 static const int kDefaultRtcpReceiverReportSsrc = 1;
 
 // Down grade resolution at most 2 times for CPU reasons.
 static const int kMaxCpuDowngrades = 2;
 
+// Minimum time interval for logging stats.
+static const int64_t kStatsLogIntervalMs = 10000;
+
 // Adds |codec| to |list|, and also adds an RTX codec if |codec|'s name is
 // recognized.
 // TODO(deadbeef): Should we add RTX codecs for external codecs whose names we
 // don't recognize?
 void AddCodecAndMaybeRtxCodec(const VideoCodec& codec,
                               std::vector<VideoCodec>* codecs) {
   codecs->push_back(codec);
   int rtx_payload_type = 0;
   if (CodecNamesEq(codec.name, kVp8CodecName)) {
     rtx_payload_type = kDefaultRtxVp8PlType;
@@ skipping 314 matching lines @@
     const std::vector<VideoCodec>& recv_codecs,
     WebRtcVideoEncoderFactory* external_encoder_factory,
     WebRtcVideoDecoderFactory* external_decoder_factory)
     : VideoMediaChannel(config),
       call_(call),
       unsignalled_ssrc_handler_(&default_unsignalled_ssrc_handler_),
       video_config_(config.video),
       external_encoder_factory_(external_encoder_factory),
       external_decoder_factory_(external_decoder_factory),
       default_send_options_(options),
-      red_disabled_by_remote_side_(false) {
+      red_disabled_by_remote_side_(false),
+      last_stats_log_ms_(-1) {
   RTC_DCHECK(thread_checker_.CalledOnValidThread());
 
   rtcp_receiver_report_ssrc_ = kDefaultRtcpReceiverReportSsrc;
   sending_ = false;
   RTC_DCHECK(ValidateCodecFormats(recv_codecs));
   recv_codecs_ = FilterSupportedCodecs(MapCodecs(recv_codecs));
 }
 
 WebRtcVideoChannel2::~WebRtcVideoChannel2() {
   for (auto& kv : send_streams_)
@@ skipping 647 matching lines @@
   if (it == receive_streams_.end()) {
     return false;
   }
 
   it->second->SetSink(sink);
   return true;
 }
 
 bool WebRtcVideoChannel2::GetStats(VideoMediaInfo* info) {
   TRACE_EVENT0("webrtc", "WebRtcVideoChannel2::GetStats");
+
+  // Log stats periodically.
+  bool log_stats = false;
+  int64_t now_ms = rtc::TimeMillis();
+  if (last_stats_log_ms_ == -1 ||
+      now_ms - last_stats_log_ms_ > kStatsLogIntervalMs) {
+    last_stats_log_ms_ = now_ms;
+    log_stats = true;
+  }
+
   info->Clear();
-  FillSenderStats(info);
-  FillReceiverStats(info);
+  FillSenderStats(info, log_stats);
+  FillReceiverStats(info, log_stats);
   webrtc::Call::Stats stats = call_->GetStats();
   FillBandwidthEstimationStats(stats, info);
   if (stats.rtt_ms != -1) {
     for (size_t i = 0; i < info->senders.size(); ++i) {
       info->senders[i].rtt_ms = stats.rtt_ms;
     }
   }
+
+  if (log_stats)
+    LOG(LS_INFO) << stats.ToString(now_ms);
+
   return true;
 }
 
-void WebRtcVideoChannel2::FillSenderStats(VideoMediaInfo* video_media_info) {
+void WebRtcVideoChannel2::FillSenderStats(VideoMediaInfo* video_media_info,
+                                          bool log_stats) {
   rtc::CritScope stream_lock(&stream_crit_);
   for (std::map<uint32_t, WebRtcVideoSendStream*>::iterator it =
            send_streams_.begin();
        it != send_streams_.end(); ++it) {
-    video_media_info->senders.push_back(it->second->GetVideoSenderInfo());
+    video_media_info->senders.push_back(
+        it->second->GetVideoSenderInfo(log_stats));
   }
 }
 
-void WebRtcVideoChannel2::FillReceiverStats(VideoMediaInfo* video_media_info) {
+void WebRtcVideoChannel2::FillReceiverStats(VideoMediaInfo* video_media_info,
+                                            bool log_stats) {
   rtc::CritScope stream_lock(&stream_crit_);
   for (std::map<uint32_t, WebRtcVideoReceiveStream*>::iterator it =
            receive_streams_.begin();
        it != receive_streams_.end(); ++it) {
-    video_media_info->receivers.push_back(it->second->GetVideoReceiverInfo());
+    video_media_info->receivers.push_back(
+        it->second->GetVideoReceiverInfo(log_stats));
   }
 }
 
 void WebRtcVideoChannel2::FillBandwidthEstimationStats(
     const webrtc::Call::Stats& stats,
     VideoMediaInfo* video_media_info) {
   BandwidthEstimationInfo bwe_info;
   bwe_info.available_send_bandwidth = stats.send_bandwidth_bps;
   bwe_info.available_recv_bandwidth = stats.recv_bandwidth_bps;
   bwe_info.bucket_delay = stats.pacer_delay_ms;
@@ skipping 704 matching lines @@
       }
     }
     sink_wants_.max_pixel_count = max_pixel_count;
     sink_wants_.max_pixel_count_step_up = max_pixel_count_step_up;
   }
   // |source_->AddOrUpdateSink| may not be called while holding |lock_| since
   // that might cause a lock order inversion.
   source_->AddOrUpdateSink(this, sink_wants_);
 }
 
-VideoSenderInfo
-WebRtcVideoChannel2::WebRtcVideoSendStream::GetVideoSenderInfo() {
+VideoSenderInfo WebRtcVideoChannel2::WebRtcVideoSendStream::GetVideoSenderInfo(
+    bool log_stats) {
   VideoSenderInfo info;
   webrtc::VideoSendStream::Stats stats;
   RTC_DCHECK(thread_checker_.CalledOnValidThread());
   {
     rtc::CritScope cs(&lock_);
     for (uint32_t ssrc : parameters_.config.rtp.ssrcs)
       info.add_ssrc(ssrc);
 
     if (parameters_.codec_settings)
       info.codec_name = parameters_.codec_settings->codec.name;
     for (size_t i = 0; i < parameters_.encoder_config.streams.size(); ++i) {
       if (i == parameters_.encoder_config.streams.size() - 1) {
         info.preferred_bitrate +=
             parameters_.encoder_config.streams[i].max_bitrate_bps;
       } else {
         info.preferred_bitrate +=
             parameters_.encoder_config.streams[i].target_bitrate_bps;
       }
     }
 
     if (stream_ == NULL)
       return info;
 
     stats = stream_->GetStats();
   }
+
+  if (log_stats)
+    LOG(LS_INFO) << stats.ToString(rtc::TimeMillis());
+
   info.adapt_changes = number_of_cpu_adapt_changes_;
   info.adapt_reason =
       cpu_restricted_counter_ <= 0 ? ADAPTREASON_NONE : ADAPTREASON_CPU;
 
   // Get bandwidth limitation info from stream_->GetStats().
   // Input resolution (output from video_adapter) can be further scaled down or
   // higher video layer(s) can be dropped due to bitrate constraints.
   // Note, adapt_changes only include changes from the video_adapter.
   if (stats.bw_limited_resolution)
     info.adapt_reason |= ADAPTREASON_BANDWIDTH;
@@ skipping 354 matching lines @@
     int payload_type) {
   for (const webrtc::VideoReceiveStream::Decoder& decoder : config_.decoders) {
     if (decoder.payload_type == payload_type) {
       return decoder.payload_name;
     }
   }
   return "";
 }
 
 VideoReceiverInfo
-WebRtcVideoChannel2::WebRtcVideoReceiveStream::GetVideoReceiverInfo() {
+WebRtcVideoChannel2::WebRtcVideoReceiveStream::GetVideoReceiverInfo(
+    bool log_stats) {
   VideoReceiverInfo info;
   info.ssrc_groups = stream_params_.ssrc_groups;
   info.add_ssrc(config_.rtp.remote_ssrc);
   webrtc::VideoReceiveStream::Stats stats = stream_->GetStats();
   info.decoder_implementation_name = stats.decoder_implementation_name;
   info.bytes_rcvd = stats.rtp_stats.transmitted.payload_bytes +
                     stats.rtp_stats.transmitted.header_bytes +
                     stats.rtp_stats.transmitted.padding_bytes;
   info.packets_rcvd = stats.rtp_stats.transmitted.packets;
   info.packets_lost = stats.rtcp_stats.cumulative_lost;
@@ skipping 18 matching lines @@
   info.jitter_buffer_ms = stats.jitter_buffer_ms;
   info.min_playout_delay_ms = stats.min_playout_delay_ms;
   info.render_delay_ms = stats.render_delay_ms;
 
   info.codec_name = GetCodecNameFromPayloadType(stats.current_payload_type);
 
   info.firs_sent = stats.rtcp_packet_type_counts.fir_packets;
   info.plis_sent = stats.rtcp_packet_type_counts.pli_packets;
   info.nacks_sent = stats.rtcp_packet_type_counts.nack_packets;
 
+  if (log_stats)
+    LOG(LS_INFO) << stats.ToString(rtc::TimeMillis());
+
   return info;
 }
 
 void WebRtcVideoChannel2::WebRtcVideoReceiveStream::SetFecDisabledRemotely(
     bool disable) {
   red_disabled_by_remote_side_ = disable;
   RecreateWebRtcStream();
 }
 
 WebRtcVideoChannel2::VideoCodecSettings::VideoCodecSettings()
@@ skipping 102 matching lines @@
         rtx_mapping[video_codecs[i].codec.id] !=
             fec_settings.red_payload_type) {
       video_codecs[i].rtx_payload_type = rtx_mapping[video_codecs[i].codec.id];
     }
   }
 
   return video_codecs;
 }
 
 }  // namespace cricket