Add periodic logging of video stats.

webrtc/media/engine/webrtcvideoengine2.cc

Index: webrtc/media/engine/webrtcvideoengine2.cc
diff --git a/webrtc/media/engine/webrtcvideoengine2.cc b/webrtc/media/engine/webrtcvideoengine2.cc
index 5da8e33e1e0d784ab4e5b879a1b19cb5cc2fbeb8..212f347ba40535212780a23048f756e1e9b7c9df 100644
--- a/webrtc/media/engine/webrtcvideoengine2.cc
+++ b/webrtc/media/engine/webrtcvideoengine2.cc
@@ -342,6 +342,9 @@ 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 = 8000;
+
 // 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
@@ -676,7 +679,8 @@ WebRtcVideoChannel2::WebRtcVideoChannel2(
       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;
@@ -1354,6 +1358,13 @@ bool WebRtcVideoChannel2::GetStats(VideoMediaInfo* info) {
       info->senders[i].rtt_ms = stats.rtt_ms;
     }
   }
+  // Log stats periodically.
+  int64_t now_ms = rtc::TimeMillis();
+  if (last_stats_log_ms_ == -1 ||
+      rtc::TimeDiff(now_ms, last_stats_log_ms_) > kStatsLogIntervalMs) {

[stefan-webrtc, 2016/08/01 11:14:09]

rtc::TimeDiff seems a bit pointless to me as all it does is to do:
return later - earlier;

I'd prefer:
now_ms - last_stats_log_ms_

[åsapersson, 2016/08/01 15:55:22]

Done.

+    last_stats_log_ms_ = now_ms;
+    LOG(LS_INFO) << stats.ToString(now_ms);
+  }
   return true;
 }
 
@@ -1554,6 +1565,7 @@ WebRtcVideoChannel2::WebRtcVideoSendStream::WebRtcVideoSendStream(
       call_(call),
       cpu_restricted_counter_(0),
       number_of_cpu_adapt_changes_(0),
+      last_stats_log_ms_(-1),
       source_(nullptr),
       external_encoder_factory_(external_encoder_factory),
       stream_(nullptr),
@@ -2123,6 +2135,15 @@ WebRtcVideoChannel2::WebRtcVideoSendStream::GetVideoSenderInfo() {
 
     stats = stream_->GetStats();
   }
+
+  // Log stats periodically.
+  int64_t now_ms = rtc::TimeMillis();
+  if (last_stats_log_ms_ == -1 ||
+      rtc::TimeDiff(now_ms, last_stats_log_ms_) > kStatsLogIntervalMs) {

[stefan-webrtc, 2016/08/01 11:14:09]

Same here

[åsapersson, 2016/08/01 15:55:22]

Done.

+    last_stats_log_ms_ = now_ms;
+    LOG(LS_INFO) << stats.ToString(now_ms);
+  }
+
   info.adapt_changes = number_of_cpu_adapt_changes_;
   info.adapt_reason =
       cpu_restricted_counter_ <= 0 ? ADAPTREASON_NONE : ADAPTREASON_CPU;
@@ -2237,6 +2258,7 @@ WebRtcVideoChannel2::WebRtcVideoReceiveStream::WebRtcVideoReceiveStream(
       config_(std::move(config)),
       red_disabled_by_remote_side_(red_disabled_by_remote_side),
       external_decoder_factory_(external_decoder_factory),
+      last_stats_log_ms_(-1),
       sink_(NULL),
       last_width_(-1),
       last_height_(-1),
@@ -2536,6 +2558,14 @@ WebRtcVideoChannel2::WebRtcVideoReceiveStream::GetVideoReceiverInfo() {
   info.plis_sent = stats.rtcp_packet_type_counts.pli_packets;
   info.nacks_sent = stats.rtcp_packet_type_counts.nack_packets;
 
+  // Log stats periodically.
+  int64_t now_ms = rtc::TimeMillis();
+  if (last_stats_log_ms_ == -1 ||
+      rtc::TimeDiff(now_ms, last_stats_log_ms_) > kStatsLogIntervalMs) {
+    last_stats_log_ms_ = now_ms;
+    LOG(LS_INFO) << stats.ToString(now_ms);
+  }
+
   return info;
 }