Log statistics of TabCapture API through UMA

content/browser/renderer_host/media/web_contents_video_capture_device.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 //
 // Implementation notes: This needs to work on a variety of hardware
 // configurations where the speed of the CPU and GPU greatly affect overall
 // performance.  Therefore, the process of capturing has been split up into a
 // pipeline of three stages.  Each stage executes on its own thread:
 //
 //   1. Capture: A bitmap is snapshotted/copied from the RenderView's backing
@@ skipping 32 matching lines @@
 #include <algorithm>
 #include <string>
 
 #include "base/basictypes.h"
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/callback_forward.h"
 #include "base/debug/trace_event.h"
 #include "base/logging.h"
 #include "base/memory/scoped_ptr.h"
+#include "base/metrics/histogram.h"
 #include "base/stringprintf.h"
 #include "base/synchronization/lock.h"
 #include "base/threading/thread.h"
 #include "base/time.h"
 #include "content/browser/renderer_host/media/web_contents_capture_util.h"
 #include "content/public/browser/browser_thread.h"
 #include "content/public/browser/render_process_host.h"
 #include "content/public/browser/render_view_host.h"
 #include "content/public/browser/render_widget_host_view.h"
 #include "content/public/browser/web_contents.h"
@@ skipping 102 matching lines @@
   void LookUpAndObserveWebContents();
 
   void CopyFromBackingStoreComplete(int frame_number,
                                     scoped_ptr<skia::PlatformBitmap> capture,
                                     const DoneCB& done_cb, bool success);
 
   // The "starting point" to find the capture source.
   const int render_process_id_;
   const int render_view_id_;
 
+  // Last known RenderView size.
+  gfx::Size last_view_size_;
+
   // If the following is NULL (normal behavior), the implementation should
   // access RenderWidgetHost via web_contents().
   RenderWidgetHost* rwh_for_testing_;
 
   DISALLOW_COPY_AND_ASSIGN(BackingStoreCopier);
 };
 
 // Renders captures (from the backing store) into video frame buffers on a
 // separate thread.  Manages use of internally-owned video frame buffers.
 class VideoFrameRenderer {
@@ skipping 68 matching lines @@
                               const base::Time& frame_timestamp,
                               const base::Closure& done_cb);
 
   base::Thread deliver_thread_;
   SynchronizedConsumer* const consumer_;
 
   // The following keep track of and log the effective frame rate (from the
   // deliver stage) whenever verbose logging is turned on.
   base::Time last_frame_rate_log_time_;
   int count_frames_rendered_;
+  int last_frame_number_;
 
   DISALLOW_COPY_AND_ASSIGN(VideoFrameDeliverer);
 };
 
 BackingStoreCopier::BackingStoreCopier(int render_process_id,
                                        int render_view_id)
     : render_process_id_(render_process_id), render_view_id_(render_view_id),
       rwh_for_testing_(NULL) {}
 
 void BackingStoreCopier::LookUpAndObserveWebContents() {
@@ skipping 54 matching lines @@
   }
 
   gfx::Size fitted_size;
   if (RenderWidgetHostView* const view = rwh->GetView()) {
     const gfx::Size& view_size = view->GetViewBounds().size();
     if (!view_size.IsEmpty()) {
       CalculateFittedSize(view_size.width(), view_size.height(),
                           desired_width, desired_height,
                           &fitted_size);
     }
+    if (view_size != last_view_size_) {
+      last_view_size_ = view_size;
+
+      // Measure the number of kilopixels.
+      UMA_HISTOGRAM_COUNTS_10000(
+          "TabCapture.ViewChangeKiloPixels",
+          view_size.width() * view_size.height() / 1024);
+    }
   }
 
   // TODO(miu): Look into tweaking the interface to CopyFromBackingStore, since
   // it seems poor to have to allocate a new skia::PlatformBitmap as an output
   // buffer for each successive frame (rather than reuse buffers).  Perhaps
   // PlatformBitmap itself should only re-Allocate when necessary?
   skia::PlatformBitmap* const bitmap = new skia::PlatformBitmap();
   scoped_ptr<skia::PlatformBitmap> capture(bitmap);
   rwh->CopyFromBackingStore(
       gfx::Rect(),
@@ skipping 186 matching lines @@
 
 void SynchronizedConsumer::OnIncomingCapturedFrame(
     const uint8* pixels, int size, const base::Time& timestamp) {
   base::AutoLock guard(consumer_lock_);
   if (wrapped_consumer_) {
     wrapped_consumer_->OnIncomingCapturedFrame(pixels, size, timestamp);
   }
 }
 
 VideoFrameDeliverer::VideoFrameDeliverer(SynchronizedConsumer* consumer)
-    : deliver_thread_("WebContentsVideo_DeliverThread"), consumer_(consumer) {
+    : deliver_thread_("WebContentsVideo_DeliverThread"),
+      consumer_(consumer),
+      last_frame_number_(0) {
   DCHECK(consumer_);
   deliver_thread_.Start();
 }
 
 void VideoFrameDeliverer::Deliver(
     int frame_number,
     const SkBitmap& frame_buffer, const base::Time& frame_timestamp,
     const base::Closure& done_cb) {
   deliver_thread_.message_loop()->PostTask(
       FROM_HERE,
@@ skipping 14 matching lines @@
   // Send the frame to the consumer.
   // Note: The consumer will do an ARGB-->YUV conversion in this callback,
   // blocking the current thread for a bit.
   SkAutoLockPixels frame_buffer_locker(frame_buffer);
   consumer_->OnIncomingCapturedFrame(
       static_cast<const uint8*>(frame_buffer.getPixels()),
       frame_buffer.getSize(),
       frame_timestamp);
 
   // Log frame rate, if verbose logging is turned on.
-  if (VLOG_IS_ON(1)) {
-    static const base::TimeDelta kFrameRateLogInterval =
-        base::TimeDelta::FromSeconds(5);
-    const base::Time& now = base::Time::Now();
-    if (last_frame_rate_log_time_.is_null()) {
+  static const base::TimeDelta kFrameRateLogInterval =
+      base::TimeDelta::FromSeconds(10);
+  const base::Time& now = base::Time::Now();
+  if (last_frame_rate_log_time_.is_null()) {
+    last_frame_rate_log_time_ = now;
+    count_frames_rendered_ = 0;
+    last_frame_number_ = frame_number;
+  } else {
+    ++count_frames_rendered_;
+    const base::TimeDelta elapsed = now - last_frame_rate_log_time_;
+    if (elapsed >= kFrameRateLogInterval) {
+      const int measured_fps =

[miu, 2013/01/04 18:05:27]

nit: It was useful to see the fractional part in the VLOG statement.  Can you
put this back to double, and static_cast<int>(measured_fps) for the
UMA_HISTOGRAM_COUNTS statement?

+          count_frames_rendered_ / elapsed.InSecondsF();
+      const int frames_elapsed = frame_number - last_frame_number_;
+      const int count_frames_dropped = frames_elapsed - count_frames_rendered_;
+      DCHECK_LE(0, count_frames_dropped);
+      UMA_HISTOGRAM_PERCENTAGE(
+          "TabCapture.FrameDropPercentage",
+          (count_frames_dropped * 100 + frames_elapsed / 2) / frames_elapsed);
+      UMA_HISTOGRAM_COUNTS("TabCapture.FrameRate", measured_fps);
+      VLOG(1) << "Current measured frame rate for CaptureMachine@" << this
+              << " is " << measured_fps << " FPS.";
       last_frame_rate_log_time_ = now;
       count_frames_rendered_ = 0;
-    } else {
-      ++count_frames_rendered_;
-      const base::TimeDelta elapsed = now - last_frame_rate_log_time_;
-      if (elapsed >= kFrameRateLogInterval) {
-        const double measured_fps =
-            count_frames_rendered_ / elapsed.InSecondsF();
-        VLOG(1) << "Current measured frame rate for CaptureMachine@" << this
-                << " is " << measured_fps << " FPS.";
-        last_frame_rate_log_time_ = now;
-        count_frames_rendered_ = 0;
-      }
+      last_frame_number_ = frame_number;
     }
   }
 
   // All done.
   done_cb.Run();
 }
 
 }  // namespace
 
 // The "meat" of the video capture implementation, which is a ref-counted class.
@@ skipping 46 matching lines @@
   // Stops capturing and notifies consumer_ of an error state.
   void Error();
 
   // Schedules the next frame capture off of the system clock, skipping frames
   // to catch-up if necessary.
   void ScheduleNextFrameCapture();
 
   // The glue between the pipeline stages.
   void StartSnapshot();
   void SnapshotComplete(int frame_number,
+                        const base::Time& start_time,
                         BackingStoreCopier::Result result,
                         scoped_ptr<skia::PlatformBitmap> capture,
                         const base::Time& capture_time);
   void RenderComplete(int frame_number,
                       const base::Time& capture_time,
                       const SkBitmap* frame_buffer);
   void DeliverComplete(const SkBitmap* frame_buffer);
 
   // Specialized RefCounted traits for CaptureMachine, so that operator delete
   // is called from an "outside" thread.  See comments for "traits" in
@@ skipping 217 matching lines @@
   if (state_ != kCapturing) {
     return;
   }
 
   if (!is_snapshotting_) {
     is_snapshotting_ = true;
 
     const BackingStoreCopier::DoneCB& done_cb =
         media::BindToLoop(manager_thread_.message_loop_proxy(),
                           base::Bind(&CaptureMachine::SnapshotComplete, this,
-                                     frame_number_));
+                                     frame_number_, base::Time::Now()));
     const base::Closure& start_cb =
         base::Bind(&BackingStoreCopier::StartCopy,
                    base::Unretained(&copier_),
                    frame_number_, settings_.width, settings_.height, done_cb);
     BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, start_cb);
   }
 
   ScheduleNextFrameCapture();
 }
 
 void CaptureMachine::SnapshotComplete(int frame_number,
+                                      const base::Time& start_time,
                                       BackingStoreCopier::Result result,
                                       scoped_ptr<skia::PlatformBitmap> capture,
                                       const base::Time& capture_time) {
   DCHECK_EQ(manager_thread_.message_loop(), MessageLoop::current());
 
   DCHECK(is_snapshotting_);
   is_snapshotting_ = false;
 
   if (state_ != kCapturing) {
     return;
   }
 
   switch (result) {
     case BackingStoreCopier::OK:
+      UMA_HISTOGRAM_TIMES("TabCapture.SnapshotTime",
+                          base::Time::Now() - start_time);
       if (num_renders_pending_ <= 1) {
         ++num_renders_pending_;
         DCHECK(capture);
         DCHECK(!capture_time.is_null());
         renderer_.Render(
             frame_number,
             capture.Pass(),
             settings_.width, settings_.height,
             media::BindToLoop(manager_thread_.message_loop_proxy(),
                               base::Bind(&CaptureMachine::RenderComplete, this,
@@ skipping 103 matching lines @@
   capturer_->SetConsumer(NULL);
   capturer_->DeAllocate();
 }
 
 const media::VideoCaptureDevice::Name&
 WebContentsVideoCaptureDevice::device_name() {
   return device_name_;
 }
 
 }  // namespace content