Chromecast: adds class to help record complex histograms.

R=lcwu@chromium.org,damienv@chromium.org
BUG=336640

Review URL: https://codereview.chromium.org/652353003

Cr-Commit-Position: refs/heads/master@{#300365}

6 files changed, 525 insertions, 0 deletions

diff --git a/chromecast/base/DEPS b/chromecast/base/DEPS
new file mode 100644
index 0000000..2e69add
--- /dev/null
+++ b/chromecast/base/DEPS
@@ -0,0 +1,7 @@
+include_rules = [
+  # chromecast/base may be depended on by many disparate parts of the Chromecast
+  # codebase. Keep dependencies small.
+  "-content",
+  "-net",
+  "-ui",
+]
diff --git a/chromecast/base/metrics/cast_histograms.h b/chromecast/base/metrics/cast_histograms.h
new file mode 100644
index 0000000..4907c1a
--- /dev/null
+++ b/chromecast/base/metrics/cast_histograms.h
@@ -0,0 +1,49 @@
+// Copyright 2014 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.
+
+#ifndef CHROMECAST_BASE_METRICS_CAST_HISTOGRAMS_H_
+#define CHROMECAST_BASE_METRICS_CAST_HISTOGRAMS_H_
+
+#include "base/metrics/histogram.h"
+
+// STATIC_HISTOGRAM_POINTER_BLOCK only calls histogram_factory_get_invocation
+// at the first time and uses the cached histogram_pointer for subsequent calls
+// through base::subtle::Release_Store() and base::subtle::Acquire_Load().
+// If the histogram name changes between subsequent calls, use this non-cached
+// version that always calls histogram_factory_get_invocation.
+#define STATIC_HISTOGRAM_POINTER_BLOCK_NO_CACHE( \
+    constant_histogram_name, \
+    histogram_add_method_invocation, \
+    histogram_factory_get_invocation) \
+  do { \
+    base::HistogramBase* histogram_pointer = histogram_factory_get_invocation; \
+    if (DCHECK_IS_ON) \
+      histogram_pointer->CheckName(constant_histogram_name); \
+    histogram_pointer->histogram_add_method_invocation; \
+  } while (0)
+
+#define UMA_HISTOGRAM_CUSTOM_TIMES_NO_CACHE( \
+    name, sample, min, max, bucket_count) \
+    STATIC_HISTOGRAM_POINTER_BLOCK_NO_CACHE(name, AddTime(sample), \
+        base::Histogram::FactoryTimeGet(name, min, max, bucket_count, \
+            base::Histogram::kUmaTargetedHistogramFlag))
+
+#define UMA_HISTOGRAM_CUSTOM_COUNTS_NO_CACHE(name, sample, min, max, \
+                                             bucket_count) \
+    STATIC_HISTOGRAM_POINTER_BLOCK_NO_CACHE(name, Add(sample), \
+        base::Histogram::FactoryGet(name, min, max, bucket_count, \
+            base::HistogramBase::kUmaTargetedHistogramFlag))
+
+#define UMA_HISTOGRAM_ENUMERATION_NO_CACHE(name, sample, boundary_value) \
+    STATIC_HISTOGRAM_POINTER_BLOCK_NO_CACHE(name, Add(sample), \
+        base::LinearHistogram::FactoryGet(name, 1, boundary_value, \
+            boundary_value + 1, base::Histogram::kUmaTargetedHistogramFlag))
+
+#define UMA_HISTOGRAM_ENUMERATION_COUNT_NO_CACHE(name, sample, count, \
+                                                 boundary_value) \
+    STATIC_HISTOGRAM_POINTER_BLOCK_NO_CACHE(name, AddCount(sample, count), \
+        base::LinearHistogram::FactoryGet(name, 1, boundary_value, \
+            boundary_value + 1, base::HistogramBase::kUmaTargetedHistogramFlag))
+
+#endif  // CHROMECAST_BASE_METRICS_CAST_HISTOGRAMS_H_
diff --git a/chromecast/base/metrics/cast_metrics_helper.cc b/chromecast/base/metrics/cast_metrics_helper.cc
new file mode 100644
index 0000000..e492355
--- /dev/null
+++ b/chromecast/base/metrics/cast_metrics_helper.cc
@@ -0,0 +1,231 @@
+// Copyright 2014 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.
+
+#include "chromecast/base/metrics/cast_metrics_helper.h"
+
+#include "base/bind.h"
+#include "base/bind_helpers.h"
+#include "base/location.h"
+#include "base/message_loop/message_loop_proxy.h"
+#include "base/metrics/histogram.h"
+#include "base/metrics/user_metrics.h"
+#include "chromecast/base/metrics/cast_histograms.h"
+
+namespace chromecast {
+namespace metrics {
+
+// A useful macro to make sure current member function runs on the valid thread.
+#define MAKE_SURE_THREAD(callback, ...)                    \
+  if (!message_loop_proxy_->BelongsToCurrentThread()) {    \
+    message_loop_proxy_->PostTask(FROM_HERE, base::Bind(   \
+        &CastMetricsHelper::callback,                      \
+        base::Unretained(this), ##__VA_ARGS__));           \
+    return;                                                \
+  }
+
+namespace {
+
+CastMetricsHelper* g_instance = NULL;
+
+// Displayed frames are logged in frames per second (but sampling can be over
+// a longer period of time, e.g. 5 seconds).
+const int kDisplayedFramesPerSecondPeriod = 1000000;
+
+// Sample every 5 seconds, represented in microseconds.
+const int kNominalVideoSamplePeriod = 5000000;
+
+}  // namespace
+
+CastMetricsHelper* CastMetricsHelper::GetInstance() {
+  DCHECK(g_instance);
+  return g_instance;
+}
+
+CastMetricsHelper::CastMetricsHelper(
+    scoped_refptr<base::MessageLoopProxy> message_loop_proxy)
+    : message_loop_proxy_(message_loop_proxy),
+      metrics_sink_(NULL) {
+  DCHECK(message_loop_proxy_.get());
+  DCHECK(!g_instance);
+  g_instance = this;
+}
+
+CastMetricsHelper::CastMetricsHelper()
+    : metrics_sink_(NULL) {
+  DCHECK(!g_instance);
+  g_instance = this;
+}
+
+CastMetricsHelper::~CastMetricsHelper() {
+  DCHECK_EQ(g_instance, this);
+  g_instance = NULL;
+}
+
+void CastMetricsHelper::TagAppStart(const std::string& arg_app_name) {
+  MAKE_SURE_THREAD(TagAppStart, arg_app_name);
+  app_name_ = arg_app_name;
+  app_start_time_ = base::TimeTicks::Now();
+  new_startup_time_ = true;
+}
+
+void CastMetricsHelper::LogMediaPlay() {
+  MAKE_SURE_THREAD(LogMediaPlay);
+  base::RecordComputedAction(GetMetricsNameWithAppName("MediaPlay", ""));
+}
+
+void CastMetricsHelper::LogMediaPause() {
+  MAKE_SURE_THREAD(LogMediaPause);
+  base::RecordComputedAction(GetMetricsNameWithAppName("MediaPause", ""));
+}
+
+void CastMetricsHelper::LogTimeToDisplayVideo() {
+  if (!new_startup_time_) {  // For faster check.
+    return;
+  }
+  MAKE_SURE_THREAD(LogTimeToDisplayVideo);
+  new_startup_time_ = false;
+  base::TimeDelta launch_time = base::TimeTicks::Now() - app_start_time_;
+  const std::string uma_name(GetMetricsNameWithAppName("Startup",
+                                                       "TimeToDisplayVideo"));
+  LogMediumTimeHistogramEvent(uma_name, launch_time);
+  LOG(INFO) << uma_name << " is " << launch_time.InSecondsF() << " seconds.";
+}
+
+void CastMetricsHelper::LogTimeToBufferAv(BufferingType buffering_type,
+                                          base::TimeDelta time) {
+  MAKE_SURE_THREAD(LogTimeToBufferAv, buffering_type, time);
+  if (time < base::TimeDelta::FromSeconds(0)) {
+    LOG(WARNING) << "Negative time";
+    return;
+  }
+
+  const std::string uma_name(GetMetricsNameWithAppName(
+      "Media",
+      (buffering_type == kInitialBuffering ? "TimeToBufferAv" :
+       buffering_type == kBufferingAfterUnderrun ?
+           "TimeToBufferAvAfterUnderrun" :
+       buffering_type == kAbortedBuffering ? "TimeToBufferAvAfterAbort" : "")));
+
+  // Histogram from 250ms to 30s with 50 buckets.
+  // The ratio between 2 consecutive buckets is:
+  // exp( (ln(30000) - ln(250)) / 50 ) = 1.1
+  LogTimeHistogramEvent(
+      uma_name,
+      time,
+      base::TimeDelta::FromMilliseconds(250),
+      base::TimeDelta::FromMilliseconds(30000),
+      50);
+}
+
+void CastMetricsHelper::ResetVideoFrameSampling() {
+  MAKE_SURE_THREAD(ResetVideoFrameSampling);
+  previous_video_stat_sample_time_ = base::TimeTicks();
+}
+
+void CastMetricsHelper::LogFramesPer5Seconds(int displayed_frames,
+                                             int dropped_frames,
+                                             int delayed_frames,
+                                             int error_frames) {
+  MAKE_SURE_THREAD(LogFramesPer5Seconds, displayed_frames, dropped_frames,
+                   delayed_frames, error_frames);
+  base::TimeTicks sample_time = base::TimeTicks::Now();
+
+  if (!previous_video_stat_sample_time_.is_null()) {
+    base::TimeDelta time_diff = sample_time - previous_video_stat_sample_time_;
+    int value = 0;
+    const int64 rounding = time_diff.InMicroseconds() / 2;
+
+    if (displayed_frames >= 0) {
+      value = (displayed_frames * kDisplayedFramesPerSecondPeriod + rounding) /
+          time_diff.InMicroseconds();
+      LogEnumerationHistogramEvent(
+          GetMetricsNameWithAppName("Media", "DisplayedFramesPerSecond"),
+          value, 50);
+    }
+    if (delayed_frames >= 0) {
+      value = (delayed_frames * kNominalVideoSamplePeriod + rounding) /
+          time_diff.InMicroseconds();
+      LogEnumerationHistogramEvent(
+          GetMetricsNameWithAppName("Media", "DelayedVideoFramesPer5Sec"),
+          value, 50);
+    }
+    if (dropped_frames >= 0) {
+      value = (dropped_frames * kNominalVideoSamplePeriod + rounding) /
+          time_diff.InMicroseconds();
+      LogEnumerationHistogramEvent(
+          GetMetricsNameWithAppName("Media", "DroppedVideoFramesPer5Sec"),
+          value, 50);
+    }
+    if (error_frames >= 0) {
+      value = (error_frames * kNominalVideoSamplePeriod + rounding) /
+          time_diff.InMicroseconds();
+      LogEnumerationHistogramEvent(
+          GetMetricsNameWithAppName("Media", "ErrorVideoFramesPer5Sec"),
+          value, 50);
+    }
+  }
+
+  previous_video_stat_sample_time_ = sample_time;
+}
+
+std::string CastMetricsHelper::GetMetricsNameWithAppName(
+    const std::string& prefix,
+    const std::string& suffix) const {
+  DCHECK(message_loop_proxy_->BelongsToCurrentThread());
+  std::string metrics_name(prefix);
+  if (!app_name_.empty()) {
+    if (!metrics_name.empty())
+      metrics_name.push_back('.');
+    metrics_name.append(app_name_);
+  }
+  if (!suffix.empty()) {
+    if (!metrics_name.empty())
+      metrics_name.push_back('.');
+    metrics_name.append(suffix);
+  }
+  return metrics_name;
+}
+
+void CastMetricsHelper::SetMetricsSink(MetricsSink* delegate) {
+  MAKE_SURE_THREAD(SetMetricsSink, delegate);
+  metrics_sink_ = delegate;
+}
+
+void CastMetricsHelper::LogEnumerationHistogramEvent(
+    const std::string& name, int value, int num_buckets) {
+  MAKE_SURE_THREAD(LogEnumerationHistogramEvent, name, value, num_buckets);
+
+  if (metrics_sink_) {
+    metrics_sink_->OnEnumerationEvent(name, value, num_buckets);
+  } else {
+    UMA_HISTOGRAM_ENUMERATION_NO_CACHE(name, value, num_buckets);
+  }
+}
+
+void CastMetricsHelper::LogTimeHistogramEvent(const std::string& name,
+                                              const base::TimeDelta& value,
+                                              const base::TimeDelta& min,
+                                              const base::TimeDelta& max,
+                                              int num_buckets) {
+  MAKE_SURE_THREAD(LogTimeHistogramEvent, name, value, min, max, num_buckets);
+
+  if (metrics_sink_) {
+    metrics_sink_->OnTimeEvent(name, value, min, max, num_buckets);
+  } else {
+    UMA_HISTOGRAM_CUSTOM_TIMES_NO_CACHE(name, value, min, max, num_buckets);
+  }
+}
+
+void CastMetricsHelper::LogMediumTimeHistogramEvent(
+    const std::string& name,
+    const base::TimeDelta& value) {
+  // Follow UMA_HISTOGRAM_MEDIUM_TIMES definition.
+  LogTimeHistogramEvent(name, value,
+                        base::TimeDelta::FromMilliseconds(10),
+                        base::TimeDelta::FromMinutes(3),
+                        50);
+}
+
+}  // namespace metrics
+}  // namespace chromecast
diff --git a/chromecast/base/metrics/cast_metrics_helper.h b/chromecast/base/metrics/cast_metrics_helper.h
new file mode 100644
index 0000000..4f06a46
--- /dev/null
+++ b/chromecast/base/metrics/cast_metrics_helper.h
@@ -0,0 +1,124 @@
+// Copyright 2014 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.
+
+#ifndef CHROMECAST_BASE_METRICS_CAST_METRICS_HELPER_H_
+#define CHROMECAST_BASE_METRICS_CAST_METRICS_HELPER_H_
+
+#include <string>
+
+#include "base/memory/ref_counted.h"
+#include "base/time/time.h"
+
+namespace base {
+class MessageLoopProxy;
+}
+
+namespace chromecast {
+namespace metrics {
+
+// Helper class for tracking complex metrics. This particularly includes
+// playback metrics that span events across time, such as "time from app launch
+// to video being rendered."
+class CastMetricsHelper {
+ public:
+  enum BufferingType {
+    kInitialBuffering,
+    kBufferingAfterUnderrun,
+    kAbortedBuffering,
+  };
+
+  class MetricsSink {
+   public:
+    virtual ~MetricsSink() {}
+
+    virtual void OnEnumerationEvent(const std::string& name,
+                                    int value, int num_buckets) = 0;
+    virtual void OnTimeEvent(const std::string& name,
+                             const base::TimeDelta& value,
+                             const base::TimeDelta& min,
+                             const base::TimeDelta& max,
+                             int num_buckets) = 0;
+  };
+
+  static CastMetricsHelper* GetInstance();
+
+  explicit CastMetricsHelper(
+      scoped_refptr<base::MessageLoopProxy> message_loop_proxy);
+  virtual ~CastMetricsHelper();
+
+  // This function stores the name and startup time of the active application.
+  virtual void TagAppStart(const std::string& app_name);
+
+  // Logs UMA record for media play/pause user actions.
+  virtual void LogMediaPlay();
+  virtual void LogMediaPause();
+
+  // Logs UMA record of the elapsed time from the app launch
+  // to the time first video frame is displayed.
+  virtual void LogTimeToDisplayVideo();
+
+  // Logs UMA record of the time needed to re-buffer A/V.
+  virtual void LogTimeToBufferAv(BufferingType buffering_type,
+                                 base::TimeDelta time);
+
+  virtual void ResetVideoFrameSampling();
+
+  // Logs UMA statistics for video decoder and rendering data.
+  // Negative values are considered invalid and will not be logged.
+  virtual void LogFramesPer5Seconds(int displayed_frames, int dropped_frames,
+                                    int delayed_frames, int error_frames);
+
+  // Returns metrics name with app name between prefix and suffix.
+  virtual std::string GetMetricsNameWithAppName(
+      const std::string& prefix,
+      const std::string& suffix) const;
+
+  // Provides a MetricsSink instance to delegate UMA event logging.
+  // Once the delegate interface is set, CastMetricsHelper will not log UMA
+  // events internally unless SetMetricsSink(NULL) is called.
+  // CastMetricsHelper can only hold one MetricsSink instance.
+  // Caller retains ownership of MetricsSink.
+  virtual void SetMetricsSink(MetricsSink* delegate);
+
+ protected:
+  // Creates a CastMetricsHelper instance with no MessageLoopProxy. This should
+  // only be used by tests, since invoking any non-overridden methods on this
+  // instance will cause a failure.
+  CastMetricsHelper();
+
+ private:
+  void LogEnumerationHistogramEvent(const std::string& name,
+                                    int value, int num_buckets);
+  void LogTimeHistogramEvent(const std::string& name,
+                             const base::TimeDelta& value,
+                             const base::TimeDelta& min,
+                             const base::TimeDelta& max,
+                             int num_buckets);
+  void LogMediumTimeHistogramEvent(const std::string& name,
+                                   const base::TimeDelta& value);
+
+  scoped_refptr<base::MessageLoopProxy> message_loop_proxy_;
+
+  // Start time of the most recent app.
+  base::TimeTicks app_start_time_;
+
+  // Currently running app name. Used to construct histogram name.
+  std::string app_name_;
+
+  // Whether a new app start time has been stored but not recorded.
+  // After the startup time has been used to generate an UMA event,
+  // this is set to false.
+  bool new_startup_time_;
+
+  base::TimeTicks previous_video_stat_sample_time_;
+
+  MetricsSink* metrics_sink_;
+
+  DISALLOW_COPY_AND_ASSIGN(CastMetricsHelper);
+};
+
+}  // namespace metrics
+}  // namespace chromecast
+
+#endif  // CHROMECAST_BASE_METRICS_CAST_METRICS_HELPER_H_
diff --git a/chromecast/base/metrics/cast_metrics_test_helper.cc b/chromecast/base/metrics/cast_metrics_test_helper.cc
new file mode 100644
index 0000000..6aa2a86
--- /dev/null
+++ b/chromecast/base/metrics/cast_metrics_test_helper.cc
@@ -0,0 +1,95 @@
+// Copyright 2014 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.
+
+#include "chromecast/base/metrics/cast_metrics_test_helper.h"
+
+#include "base/logging.h"
+#include "base/macros.h"
+#include "chromecast/base/metrics/cast_metrics_helper.h"
+
+namespace chromecast {
+namespace metrics {
+
+namespace {
+
+class CastMetricsHelperStub : public CastMetricsHelper {
+ public:
+  CastMetricsHelperStub();
+  virtual ~CastMetricsHelperStub();
+
+  virtual void TagAppStart(const std::string& arg_app_name) override;
+  virtual void LogMediaPlay() override;
+  virtual void LogMediaPause() override;
+  virtual void LogTimeToDisplayVideo() override;
+  virtual void LogTimeToBufferAv(BufferingType buffering_type,
+                                 base::TimeDelta time) override;
+  virtual void ResetVideoFrameSampling() override;
+  virtual void LogFramesPer5Seconds(
+      int displayed_frames, int dropped_frames,
+      int delayed_frames, int error_frames) override;
+  virtual std::string GetMetricsNameWithAppName(
+      const std::string& prefix, const std::string& suffix) const override;
+  virtual void SetMetricsSink(MetricsSink* delegate) override;
+
+ private:
+  DISALLOW_COPY_AND_ASSIGN(CastMetricsHelperStub);
+};
+
+bool stub_instance_exists = false;
+
+CastMetricsHelperStub::CastMetricsHelperStub()
+    : CastMetricsHelper() {
+  DCHECK(!stub_instance_exists);
+  stub_instance_exists = true;
+}
+
+CastMetricsHelperStub::~CastMetricsHelperStub() {
+  DCHECK(stub_instance_exists);
+  stub_instance_exists = false;
+}
+
+void CastMetricsHelperStub::TagAppStart(const std::string& arg_app_name) {
+}
+
+void CastMetricsHelperStub::LogMediaPlay() {
+}
+
+void CastMetricsHelperStub::LogMediaPause() {
+}
+
+void CastMetricsHelperStub::LogTimeToDisplayVideo() {
+}
+
+void CastMetricsHelperStub::LogTimeToBufferAv(BufferingType buffering_type,
+                                              base::TimeDelta time) {
+}
+
+void CastMetricsHelperStub::ResetVideoFrameSampling() {
+}
+
+void CastMetricsHelperStub::LogFramesPer5Seconds(int displayed_frames,
+                                                 int dropped_frames,
+                                                 int delayed_frames,
+                                                 int error_frames) {
+}
+
+std::string CastMetricsHelperStub::GetMetricsNameWithAppName(
+    const std::string& prefix,
+    const std::string& suffix) const {
+  return "";
+}
+
+void CastMetricsHelperStub::SetMetricsSink(MetricsSink* delegate) {
+}
+
+}  // namespace
+
+void InitializeMetricsHelperForTesting() {
+  if (!stub_instance_exists) {
+    new CastMetricsHelperStub();
+  }
+}
+
+}  // namespace metrics
+}  // namespace chromecast
diff --git a/chromecast/base/metrics/cast_metrics_test_helper.h b/chromecast/base/metrics/cast_metrics_test_helper.h
new file mode 100644
index 0000000..a1eafed
--- /dev/null
+++ b/chromecast/base/metrics/cast_metrics_test_helper.h
@@ -0,0 +1,19 @@
+// Copyright 2014 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.
+
+#ifndef CHROMECAST_BASE_METRICS_CAST_METRICS_TEST_HELPER_H_
+#define CHROMECAST_BASE_METRICS_CAST_METRICS_TEST_HELPER_H_
+
+namespace chromecast {
+namespace metrics {
+
+// Creates and initializes a metrics helper stub for the current process, in
+// which all operations are no-ops. May be safely called multiple times per
+// process.
+void InitializeMetricsHelperForTesting();
+
+}  // namespace metrics
+}  // namespace chromecast
+
+#endif  // CHROMECAST_BASE_METRICS_CAST_METRICS_TEST_HELPER_H_