chromecast/base/metrics/cast_metrics_helper.cc

   1 // Copyright 2014 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "chromecast/base/metrics/cast_metrics_helper.h"
   6
   7 #include "base/bind.h"
   8 #include "base/bind_helpers.h"
   9 #include "base/location.h"
  10 #include "base/message_loop/message_loop_proxy.h"
  11 #include "base/metrics/histogram.h"
  12 #include "base/metrics/user_metrics.h"
  13 #include "base/strings/string_split.h"
  14 #include "base/strings/string_util.h"
  15 #include "chromecast/base/metrics/cast_histograms.h"
  16 #include "chromecast/base/metrics/grouped_histogram.h"
  17
  18 namespace chromecast {
  19 namespace metrics {
  20
  21 // A useful macro to make sure current member function runs on the valid thread.
  22 #define MAKE_SURE_THREAD(callback, ...)                    \
  23   if (!message_loop_proxy_->BelongsToCurrentThread()) {    \
  24     message_loop_proxy_->PostTask(FROM_HERE, base::Bind(   \
  25         &CastMetricsHelper::callback,                      \
  26         base::Unretained(this), ##__VA_ARGS__));           \
  27     return;                                                \
  28   }
  29
  30 namespace {
  31
  32 CastMetricsHelper* g_instance = NULL;
  33
  34 // Displayed frames are logged in frames per second (but sampling can be over
  35 // a longer period of time, e.g. 5 seconds).
  36 const int kDisplayedFramesPerSecondPeriod = 1000000;
  37
  38 // Sample every 5 seconds, represented in microseconds.
  39 const int kNominalVideoSamplePeriod = 5000000;
  40
  41 const char kMetricsNameAppInfoDelimiter = '#';
  42
  43 }  // namespace
  44
  45 // static
  46
  47 // NOTE(gfhuang): This is a hacky way to encode/decode app infos into a
  48 // string. Mainly because it's hard to add another metrics serialization type
  49 // into components/metrics/serialization/.
  50 // static
  51 bool CastMetricsHelper::DecodeAppInfoFromMetricsName(
  52     const std::string& metrics_name,
  53     std::string* action_name,
  54     std::string* app_id,
  55     std::string* session_id,
  56     std::string* sdk_version) {
  57   DCHECK(action_name);
  58   DCHECK(app_id);
  59   DCHECK(session_id);
  60   DCHECK(sdk_version);
  61   if (metrics_name.find(kMetricsNameAppInfoDelimiter) == std::string::npos)
  62     return false;
  63
  64   std::vector<std::string> tokens;
  65   base::SplitString(metrics_name, kMetricsNameAppInfoDelimiter, &tokens);
  66   DCHECK_EQ(tokens.size(), 4u);
  67   // The order of tokens should match EncodeAppInfoIntoMetricsName().
  68   *action_name = tokens[0];
  69   *app_id = tokens[1];
  70   *session_id = tokens[2];
  71   *sdk_version = tokens[3];
  72   return true;
  73 }
  74
  75 // static
  76 std::string CastMetricsHelper::EncodeAppInfoIntoMetricsName(
  77     const std::string& action_name,
  78     const std::string& app_id,
  79     const std::string& session_id,
  80     const std::string& sdk_version) {
  81   std::vector<std::string> parts;
  82   parts.push_back(action_name);
  83   parts.push_back(app_id);
  84   parts.push_back(session_id);
  85   parts.push_back(sdk_version);
  86   return JoinString(parts, kMetricsNameAppInfoDelimiter);
  87 }
  88
  89 // static
  90 CastMetricsHelper* CastMetricsHelper::GetInstance() {
  91   DCHECK(g_instance);
  92   return g_instance;
  93 }
  94
  95 CastMetricsHelper::CastMetricsHelper(
  96     scoped_refptr<base::MessageLoopProxy> message_loop_proxy)
  97     : message_loop_proxy_(message_loop_proxy),
  98       metrics_sink_(NULL),
  99       record_action_callback_(base::Bind(&base::RecordComputedAction)) {
 100   DCHECK(message_loop_proxy_.get());
 101   DCHECK(!g_instance);
 102   g_instance = this;
 103 }
 104
 105 CastMetricsHelper::CastMetricsHelper()
 106     : metrics_sink_(NULL) {
 107   DCHECK(!g_instance);
 108   g_instance = this;
 109 }
 110
 111 CastMetricsHelper::~CastMetricsHelper() {
 112   DCHECK_EQ(g_instance, this);
 113   g_instance = NULL;
 114 }
 115
 116 void CastMetricsHelper::UpdateCurrentAppInfo(const std::string& app_id,
 117                                              const std::string& session_id) {
 118   MAKE_SURE_THREAD(UpdateCurrentAppInfo, app_id, session_id);
 119   app_id_ = app_id;
 120   session_id_ = session_id;
 121   app_start_time_ = base::TimeTicks::Now();
 122   new_startup_time_ = true;
 123   TagAppStartForGroupedHistograms(app_id_);
 124   sdk_version_.clear();
 125 }
 126
 127 void CastMetricsHelper::UpdateSDKInfo(const std::string& sdk_version) {
 128   MAKE_SURE_THREAD(UpdateSDKInfo, sdk_version);
 129   sdk_version_ = sdk_version;
 130 }
 131
 132 void CastMetricsHelper::LogMediaPlay() {
 133   MAKE_SURE_THREAD(LogMediaPlay);
 134   RecordSimpleAction(EncodeAppInfoIntoMetricsName(
 135       "MediaPlay",
 136       app_id_,
 137       session_id_,
 138       sdk_version_));
 139 }
 140
 141 void CastMetricsHelper::LogMediaPause() {
 142   MAKE_SURE_THREAD(LogMediaPause);
 143   RecordSimpleAction(EncodeAppInfoIntoMetricsName(
 144       "MediaPause",
 145       app_id_,
 146       session_id_,
 147       sdk_version_));
 148 }
 149
 150 void CastMetricsHelper::LogTimeToFirstPaint() {
 151   MAKE_SURE_THREAD(LogTimeToFirstPaint);
 152   base::TimeDelta launch_time = base::TimeTicks::Now() - app_start_time_;
 153   const std::string uma_name(GetMetricsNameWithAppName("Startup",
 154                                                        "TimeToFirstPaint"));
 155   LogMediumTimeHistogramEvent(uma_name, launch_time);
 156   LOG(INFO) << uma_name << " is " << launch_time.InSecondsF() << " seconds.";
 157 }
 158
 159 void CastMetricsHelper::LogTimeToDisplayVideo() {
 160   if (!new_startup_time_) {  // For faster check.
 161     return;
 162   }
 163   MAKE_SURE_THREAD(LogTimeToDisplayVideo);
 164   new_startup_time_ = false;
 165   base::TimeDelta launch_time = base::TimeTicks::Now() - app_start_time_;
 166   const std::string uma_name(GetMetricsNameWithAppName("Startup",
 167                                                        "TimeToDisplayVideo"));
 168   LogMediumTimeHistogramEvent(uma_name, launch_time);
 169   LOG(INFO) << uma_name << " is " << launch_time.InSecondsF() << " seconds.";
 170 }
 171
 172 void CastMetricsHelper::LogTimeToBufferAv(BufferingType buffering_type,
 173                                           base::TimeDelta time) {
 174   MAKE_SURE_THREAD(LogTimeToBufferAv, buffering_type, time);
 175   if (time < base::TimeDelta::FromSeconds(0)) {
 176     LOG(WARNING) << "Negative time";
 177     return;
 178   }
 179
 180   const std::string uma_name(GetMetricsNameWithAppName(
 181       "Media",
 182       (buffering_type == kInitialBuffering ? "TimeToBufferAv" :
 183        buffering_type == kBufferingAfterUnderrun ?
 184            "TimeToBufferAvAfterUnderrun" :
 185        buffering_type == kAbortedBuffering ? "TimeToBufferAvAfterAbort" : "")));
 186
 187   // Histogram from 250ms to 30s with 50 buckets.
 188   // The ratio between 2 consecutive buckets is:
 189   // exp( (ln(30000) - ln(250)) / 50 ) = 1.1
 190   LogTimeHistogramEvent(
 191       uma_name,
 192       time,
 193       base::TimeDelta::FromMilliseconds(250),
 194       base::TimeDelta::FromMilliseconds(30000),
 195       50);
 196 }
 197
 198 void CastMetricsHelper::ResetVideoFrameSampling() {
 199   MAKE_SURE_THREAD(ResetVideoFrameSampling);
 200   previous_video_stat_sample_time_ = base::TimeTicks();
 201 }
 202
 203 void CastMetricsHelper::LogFramesPer5Seconds(int displayed_frames,
 204                                              int dropped_frames,
 205                                              int delayed_frames,
 206                                              int error_frames) {
 207   MAKE_SURE_THREAD(LogFramesPer5Seconds, displayed_frames, dropped_frames,
 208                    delayed_frames, error_frames);
 209   base::TimeTicks sample_time = base::TimeTicks::Now();
 210
 211   if (!previous_video_stat_sample_time_.is_null()) {
 212     base::TimeDelta time_diff = sample_time - previous_video_stat_sample_time_;
 213     int value = 0;
 214     const int64 rounding = time_diff.InMicroseconds() / 2;
 215
 216     if (displayed_frames >= 0) {
 217       value = (displayed_frames * kDisplayedFramesPerSecondPeriod + rounding) /
 218           time_diff.InMicroseconds();
 219       LogEnumerationHistogramEvent(
 220           GetMetricsNameWithAppName("Media", "DisplayedFramesPerSecond"),
 221           value, 50);
 222     }
 223     if (delayed_frames >= 0) {
 224       value = (delayed_frames * kNominalVideoSamplePeriod + rounding) /
 225           time_diff.InMicroseconds();
 226       LogEnumerationHistogramEvent(
 227           GetMetricsNameWithAppName("Media", "DelayedVideoFramesPer5Sec"),
 228           value, 50);
 229     }
 230     if (dropped_frames >= 0) {
 231       value = (dropped_frames * kNominalVideoSamplePeriod + rounding) /
 232           time_diff.InMicroseconds();
 233       LogEnumerationHistogramEvent(
 234           GetMetricsNameWithAppName("Media", "DroppedVideoFramesPer5Sec"),
 235           value, 50);
 236     }
 237     if (error_frames >= 0) {
 238       value = (error_frames * kNominalVideoSamplePeriod + rounding) /
 239           time_diff.InMicroseconds();
 240       LogEnumerationHistogramEvent(
 241           GetMetricsNameWithAppName("Media", "ErrorVideoFramesPer5Sec"),
 242           value, 50);
 243     }
 244   }
 245
 246   previous_video_stat_sample_time_ = sample_time;
 247 }
 248
 249 std::string CastMetricsHelper::GetMetricsNameWithAppName(
 250     const std::string& prefix,
 251     const std::string& suffix) const {
 252   DCHECK(message_loop_proxy_->BelongsToCurrentThread());
 253   std::string metrics_name(prefix);
 254   if (!app_id_.empty()) {
 255     if (!metrics_name.empty())
 256       metrics_name.push_back('.');
 257     metrics_name.append(app_id_);
 258   }
 259   if (!suffix.empty()) {
 260     if (!metrics_name.empty())
 261       metrics_name.push_back('.');
 262     metrics_name.append(suffix);
 263   }
 264   return metrics_name;
 265 }
 266
 267 void CastMetricsHelper::SetMetricsSink(MetricsSink* delegate) {
 268   MAKE_SURE_THREAD(SetMetricsSink, delegate);
 269   metrics_sink_ = delegate;
 270 }
 271
 272 void CastMetricsHelper::SetRecordActionCallback(
 273       const RecordActionCallback& callback) {
 274   DCHECK(message_loop_proxy_->BelongsToCurrentThread());
 275   record_action_callback_ = callback;
 276 }
 277
 278 void CastMetricsHelper::RecordSimpleAction(const std::string& action) {
 279   MAKE_SURE_THREAD(RecordSimpleAction, action);
 280
 281   if (metrics_sink_) {
 282     metrics_sink_->OnAction(action);
 283   } else {
 284     record_action_callback_.Run(action);
 285   }
 286 }
 287
 288 void CastMetricsHelper::LogEnumerationHistogramEvent(
 289     const std::string& name, int value, int num_buckets) {
 290   MAKE_SURE_THREAD(LogEnumerationHistogramEvent, name, value, num_buckets);
 291
 292   if (metrics_sink_) {
 293     metrics_sink_->OnEnumerationEvent(name, value, num_buckets);
 294   } else {
 295     UMA_HISTOGRAM_ENUMERATION_NO_CACHE(name, value, num_buckets);
 296   }
 297 }
 298
 299 void CastMetricsHelper::LogTimeHistogramEvent(const std::string& name,
 300                                               const base::TimeDelta& value,
 301                                               const base::TimeDelta& min,
 302                                               const base::TimeDelta& max,
 303                                               int num_buckets) {
 304   MAKE_SURE_THREAD(LogTimeHistogramEvent, name, value, min, max, num_buckets);
 305
 306   if (metrics_sink_) {
 307     metrics_sink_->OnTimeEvent(name, value, min, max, num_buckets);
 308   } else {
 309     UMA_HISTOGRAM_CUSTOM_TIMES_NO_CACHE(name, value, min, max, num_buckets);
 310   }
 311 }
 312
 313 void CastMetricsHelper::LogMediumTimeHistogramEvent(
 314     const std::string& name,
 315     const base::TimeDelta& value) {
 316   // Follow UMA_HISTOGRAM_MEDIUM_TIMES definition.
 317   LogTimeHistogramEvent(name, value,
 318                         base::TimeDelta::FromMilliseconds(10),
 319                         base::TimeDelta::FromMinutes(3),
 320                         50);
 321 }
 322
 323 }  // namespace metrics
 324 }  // namespace chromecast