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.
5 #include "chromecast/base/metrics/cast_metrics_helper.h"
8 #include "base/bind_helpers.h"
9 #include "base/location.h"
10 #include "base/metrics/histogram.h"
11 #include "base/metrics/user_metrics.h"
12 #include "base/single_thread_task_runner.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"
18 namespace chromecast
{
21 // A useful macro to make sure current member function runs on the valid thread.
22 #define MAKE_SURE_THREAD(callback, ...) \
23 if (!task_runner_->BelongsToCurrentThread()) { \
24 task_runner_->PostTask(FROM_HERE, \
25 base::Bind(&CastMetricsHelper::callback, \
26 base::Unretained(this), ##__VA_ARGS__)); \
32 CastMetricsHelper
* g_instance
= NULL
;
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;
38 // Sample every 5 seconds, represented in microseconds.
39 const int kNominalVideoSamplePeriod
= 5000000;
41 const char kMetricsNameAppInfoDelimiter
= '#';
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/.
51 bool CastMetricsHelper::DecodeAppInfoFromMetricsName(
52 const std::string
& metrics_name
,
53 std::string
* action_name
,
55 std::string
* session_id
,
56 std::string
* sdk_version
) {
61 if (metrics_name
.find(kMetricsNameAppInfoDelimiter
) == std::string::npos
)
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];
70 *session_id
= tokens
[2];
71 *sdk_version
= tokens
[3];
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
);
90 CastMetricsHelper
* CastMetricsHelper::GetInstance() {
95 CastMetricsHelper::CastMetricsHelper(
96 scoped_refptr
<base::SingleThreadTaskRunner
> task_runner
)
97 : task_runner_(task_runner
),
99 record_action_callback_(base::Bind(&base::RecordComputedAction
)) {
100 DCHECK(task_runner_
.get());
105 CastMetricsHelper::CastMetricsHelper()
106 : metrics_sink_(NULL
) {
111 CastMetricsHelper::~CastMetricsHelper() {
112 DCHECK_EQ(g_instance
, this);
116 void CastMetricsHelper::UpdateCurrentAppInfo(const std::string
& app_id
,
117 const std::string
& session_id
) {
118 MAKE_SURE_THREAD(UpdateCurrentAppInfo
, app_id
, session_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();
127 void CastMetricsHelper::UpdateSDKInfo(const std::string
& sdk_version
) {
128 MAKE_SURE_THREAD(UpdateSDKInfo
, sdk_version
);
129 sdk_version_
= sdk_version
;
132 void CastMetricsHelper::LogMediaPlay() {
133 MAKE_SURE_THREAD(LogMediaPlay
);
134 RecordSimpleAction(EncodeAppInfoIntoMetricsName(
141 void CastMetricsHelper::LogMediaPause() {
142 MAKE_SURE_THREAD(LogMediaPause
);
143 RecordSimpleAction(EncodeAppInfoIntoMetricsName(
150 void CastMetricsHelper::LogTimeToFirstPaint() {
151 MAKE_SURE_THREAD(LogTimeToFirstPaint
);
154 base::TimeDelta launch_time
= base::TimeTicks::Now() - app_start_time_
;
155 const std::string
uma_name(GetMetricsNameWithAppName("Startup",
156 "TimeToFirstPaint"));
157 LogMediumTimeHistogramEvent(uma_name
, launch_time
);
158 LOG(INFO
) << uma_name
<< " is " << launch_time
.InSecondsF() << " seconds.";
161 void CastMetricsHelper::LogTimeToDisplayVideo() {
162 if (!new_startup_time_
) { // For faster check.
165 MAKE_SURE_THREAD(LogTimeToDisplayVideo
);
166 new_startup_time_
= false;
167 base::TimeDelta launch_time
= base::TimeTicks::Now() - app_start_time_
;
168 const std::string
uma_name(GetMetricsNameWithAppName("Startup",
169 "TimeToDisplayVideo"));
170 LogMediumTimeHistogramEvent(uma_name
, launch_time
);
171 LOG(INFO
) << uma_name
<< " is " << launch_time
.InSecondsF() << " seconds.";
174 void CastMetricsHelper::LogTimeToBufferAv(BufferingType buffering_type
,
175 base::TimeDelta time
) {
176 MAKE_SURE_THREAD(LogTimeToBufferAv
, buffering_type
, time
);
177 if (time
< base::TimeDelta::FromSeconds(0)) {
178 LOG(WARNING
) << "Negative time";
182 const std::string
uma_name(GetMetricsNameWithAppName(
184 (buffering_type
== kInitialBuffering
? "TimeToBufferAv" :
185 buffering_type
== kBufferingAfterUnderrun
?
186 "TimeToBufferAvAfterUnderrun" :
187 buffering_type
== kAbortedBuffering
? "TimeToBufferAvAfterAbort" : "")));
189 // Histogram from 250ms to 30s with 50 buckets.
190 // The ratio between 2 consecutive buckets is:
191 // exp( (ln(30000) - ln(250)) / 50 ) = 1.1
192 LogTimeHistogramEvent(
195 base::TimeDelta::FromMilliseconds(250),
196 base::TimeDelta::FromMilliseconds(30000),
200 void CastMetricsHelper::ResetVideoFrameSampling() {
201 MAKE_SURE_THREAD(ResetVideoFrameSampling
);
202 previous_video_stat_sample_time_
= base::TimeTicks();
205 void CastMetricsHelper::LogFramesPer5Seconds(int displayed_frames
,
209 MAKE_SURE_THREAD(LogFramesPer5Seconds
, displayed_frames
, dropped_frames
,
210 delayed_frames
, error_frames
);
211 base::TimeTicks sample_time
= base::TimeTicks::Now();
213 if (!previous_video_stat_sample_time_
.is_null()) {
214 base::TimeDelta time_diff
= sample_time
- previous_video_stat_sample_time_
;
216 const int64 rounding
= time_diff
.InMicroseconds() / 2;
218 if (displayed_frames
>= 0) {
219 value
= (displayed_frames
* kDisplayedFramesPerSecondPeriod
+ rounding
) /
220 time_diff
.InMicroseconds();
221 LogEnumerationHistogramEvent(
222 GetMetricsNameWithAppName("Media", "DisplayedFramesPerSecond"),
225 if (delayed_frames
>= 0) {
226 value
= (delayed_frames
* kNominalVideoSamplePeriod
+ rounding
) /
227 time_diff
.InMicroseconds();
228 LogEnumerationHistogramEvent(
229 GetMetricsNameWithAppName("Media", "DelayedVideoFramesPer5Sec"),
232 if (dropped_frames
>= 0) {
233 value
= (dropped_frames
* kNominalVideoSamplePeriod
+ rounding
) /
234 time_diff
.InMicroseconds();
235 LogEnumerationHistogramEvent(
236 GetMetricsNameWithAppName("Media", "DroppedVideoFramesPer5Sec"),
239 if (error_frames
>= 0) {
240 value
= (error_frames
* kNominalVideoSamplePeriod
+ rounding
) /
241 time_diff
.InMicroseconds();
242 LogEnumerationHistogramEvent(
243 GetMetricsNameWithAppName("Media", "ErrorVideoFramesPer5Sec"),
248 previous_video_stat_sample_time_
= sample_time
;
251 std::string
CastMetricsHelper::GetMetricsNameWithAppName(
252 const std::string
& prefix
,
253 const std::string
& suffix
) const {
254 DCHECK(task_runner_
->BelongsToCurrentThread());
255 std::string
metrics_name(prefix
);
256 if (!app_id_
.empty()) {
257 if (!metrics_name
.empty())
258 metrics_name
.push_back('.');
259 metrics_name
.append(app_id_
);
261 if (!suffix
.empty()) {
262 if (!metrics_name
.empty())
263 metrics_name
.push_back('.');
264 metrics_name
.append(suffix
);
269 void CastMetricsHelper::SetMetricsSink(MetricsSink
* delegate
) {
270 MAKE_SURE_THREAD(SetMetricsSink
, delegate
);
271 metrics_sink_
= delegate
;
274 void CastMetricsHelper::SetRecordActionCallback(
275 const RecordActionCallback
& callback
) {
276 DCHECK(task_runner_
->BelongsToCurrentThread());
277 record_action_callback_
= callback
;
280 void CastMetricsHelper::RecordSimpleAction(const std::string
& action
) {
281 MAKE_SURE_THREAD(RecordSimpleAction
, action
);
284 metrics_sink_
->OnAction(action
);
286 record_action_callback_
.Run(action
);
290 void CastMetricsHelper::LogEnumerationHistogramEvent(
291 const std::string
& name
, int value
, int num_buckets
) {
292 MAKE_SURE_THREAD(LogEnumerationHistogramEvent
, name
, value
, num_buckets
);
295 metrics_sink_
->OnEnumerationEvent(name
, value
, num_buckets
);
297 UMA_HISTOGRAM_ENUMERATION_NO_CACHE(name
, value
, num_buckets
);
301 void CastMetricsHelper::LogTimeHistogramEvent(const std::string
& name
,
302 const base::TimeDelta
& value
,
303 const base::TimeDelta
& min
,
304 const base::TimeDelta
& max
,
306 MAKE_SURE_THREAD(LogTimeHistogramEvent
, name
, value
, min
, max
, num_buckets
);
309 metrics_sink_
->OnTimeEvent(name
, value
, min
, max
, num_buckets
);
311 UMA_HISTOGRAM_CUSTOM_TIMES_NO_CACHE(name
, value
, min
, max
, num_buckets
);
315 void CastMetricsHelper::LogMediumTimeHistogramEvent(
316 const std::string
& name
,
317 const base::TimeDelta
& value
) {
318 // Follow UMA_HISTOGRAM_MEDIUM_TIMES definition.
319 LogTimeHistogramEvent(name
, value
,
320 base::TimeDelta::FromMilliseconds(10),
321 base::TimeDelta::FromMinutes(3),
325 } // namespace metrics
326 } // namespace chromecast