commit 0a5792e90746dcdc8b032ae7c4e43d54be5ce2ff
author Stefan Holmer <stefan@webrtc.org> Fri Oct 05 11:47:12 2018
committer Stefan Holmer <stefan@webrtc.org> Fri Oct 05 13:19:11 2018
tree a8daad615af58858267506b0d88c05d572e4af6d
parent 96a0f6191781e6e381c15b83827ef31ecf0f8ef5

Add UMA metric and logging of frames dropped in the render queue.

Bug: b/80195113
Change-Id: I7a696fe58ccf4e2bc7502438c2f58beb65848d25
Reviewed-on: https://webrtc-review.googlesource.com/c/104062
Reviewed-by: Rasmus Brandt <brandtr@webrtc.org>
Commit-Queue: Stefan Holmer <stefan@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#25016}

common_video/BUILD.gn

diff --git a/common_video/BUILD.gn b/common_video/BUILD.gn
index a58141b..b69c451 100644
--- a/common_video/BUILD.gn
+++ b/common_video/BUILD.gn
@@ -52,6 +52,7 @@
     "../rtc_base:rtc_base",
     "../rtc_base:rtc_task_queue",
     "../rtc_base:safe_minmax",
+    "../system_wrappers:metrics",
     "//third_party/abseil-cpp/absl/types:optional",
     "//third_party/libyuv",
   ]

common_video/video_render_frames.cc

diff --git a/common_video/video_render_frames.cc b/common_video/video_render_frames.cc
index 376d8e0..5a0b0b0 100644
--- a/common_video/video_render_frames.cc
+++ b/common_video/video_render_frames.cc
@@ -14,6 +14,7 @@
 
 #include "rtc_base/logging.h"
 #include "rtc_base/timeutils.h"
+#include "system_wrappers/include/metrics.h"
 
 namespace webrtc {
 namespace {
@@ -37,7 +38,13 @@
 VideoRenderFrames::VideoRenderFrames(uint32_t render_delay_ms)
     : render_delay_ms_(EnsureValidRenderDelay(render_delay_ms)) {}
 
-VideoRenderFrames::~VideoRenderFrames() = default;
+VideoRenderFrames::~VideoRenderFrames() {
+  frames_dropped_ += incoming_frames_.size();
+  RTC_HISTOGRAM_COUNTS_1000("WebRTC.Video.DroppedFrames.RenderQueue",
+                            frames_dropped_);
+  RTC_LOG(LS_INFO) << "WebRTC.Video.DroppedFrames.RenderQueue "
+                   << frames_dropped_;
+}
 
 int32_t VideoRenderFrames::AddFrame(VideoFrame&& new_frame) {
   const int64_t time_now = rtc::TimeMillis();
@@ -47,12 +54,14 @@
   if (!incoming_frames_.empty() &&
       new_frame.render_time_ms() + kOldRenderTimestampMS < time_now) {
     RTC_LOG(LS_WARNING) << "Too old frame, timestamp=" << new_frame.timestamp();
+    ++frames_dropped_;
     return -1;
   }
 
   if (new_frame.render_time_ms() > time_now + kFutureRenderTimestampMS) {
     RTC_LOG(LS_WARNING) << "Frame too long into the future, timestamp="
                         << new_frame.timestamp();
+    ++frames_dropped_;
     return -1;
   }
 
@@ -62,15 +71,17 @@
                         << ", latest=" << last_render_time_ms_;
     // For more details, see bug:
     // https://bugs.chromium.org/p/webrtc/issues/detail?id=7253
+    ++frames_dropped_;
     return -1;
   }
 
   last_render_time_ms_ = new_frame.render_time_ms();
   incoming_frames_.emplace_back(std::move(new_frame));
 
-  if (incoming_frames_.size() > kMaxIncomingFramesBeforeLogged)
+  if (incoming_frames_.size() > kMaxIncomingFramesBeforeLogged) {
     RTC_LOG(LS_WARNING) << "Stored incoming frames: "
                         << incoming_frames_.size();
+  }
   return static_cast<int32_t>(incoming_frames_.size());
 }
 
@@ -78,6 +89,9 @@
   absl::optional<VideoFrame> render_frame;
   // Get the newest frame that can be released for rendering.
   while (!incoming_frames_.empty() && TimeToNextFrameRelease() <= 0) {
+    if (render_frame) {
+      ++frames_dropped_;
+    }
     render_frame = std::move(incoming_frames_.front());
     incoming_frames_.pop_front();
   }

common_video/video_render_frames.h

diff --git a/common_video/video_render_frames.h b/common_video/video_render_frames.h
index 0b47e0a..2226577 100644
--- a/common_video/video_render_frames.h
+++ b/common_video/video_render_frames.h
@@ -46,6 +46,7 @@
   const uint32_t render_delay_ms_;
 
   int64_t last_render_time_ms_ = 0;
+  size_t frames_dropped_ = 0;
 };
 
 }  // namespace webrtc

video/send_statistics_proxy.cc

diff --git a/video/send_statistics_proxy.cc b/video/send_statistics_proxy.cc
index a80b5a5..9839ed7 100644
--- a/video/send_statistics_proxy.cc
+++ b/video/send_statistics_proxy.cc
@@ -502,7 +502,7 @@
         RTC_HISTOGRAMS_PERCENTAGE(
             kIndex, uma_prefix_ + "SentPacketsLostInPercent", fraction_lost);
         log_stream << uma_prefix_ << "SentPacketsLostInPercent "
-                   << fraction_lost;
+                   << fraction_lost << "\n";
       }
 
       // The RTCP packet type counters, delivered via the