1//
2// Copyright (C) 2014 The Android Open Source Project
3//
4// Licensed under the Apache License, Version 2.0 (the "License");
5// you may not use this file except in compliance with the License.
6// You may obtain a copy of the License at
7//
8//      http://www.apache.org/licenses/LICENSE-2.0
9//
10// Unless required by applicable law or agreed to in writing, software
11// distributed under the License is distributed on an "AS IS" BASIS,
12// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13// See the License for the specific language governing permissions and
14// limitations under the License.
15//
16
17#include "update_engine/metrics.h"
18
19#include <string>
20
21#include <base/logging.h>
22#include <metrics/metrics_library.h>
23
24#include "update_engine/common/clock_interface.h"
25#include "update_engine/common/constants.h"
26#include "update_engine/common/prefs_interface.h"
27#include "update_engine/common/utils.h"
28#include "update_engine/metrics_utils.h"
29#include "update_engine/system_state.h"
30
31using std::string;
32
33namespace chromeos_update_engine {
34
35namespace metrics {
36
37// UpdateEngine.Daily.* metrics.
38const char kMetricDailyOSAgeDays[] = "UpdateEngine.Daily.OSAgeDays";
39
40// UpdateEngine.Check.* metrics.
41const char kMetricCheckDownloadErrorCode[] =
42    "UpdateEngine.Check.DownloadErrorCode";
43const char kMetricCheckReaction[] = "UpdateEngine.Check.Reaction";
44const char kMetricCheckResult[] = "UpdateEngine.Check.Result";
45const char kMetricCheckTimeSinceLastCheckMinutes[] =
46    "UpdateEngine.Check.TimeSinceLastCheckMinutes";
47const char kMetricCheckTimeSinceLastCheckUptimeMinutes[] =
48    "UpdateEngine.Check.TimeSinceLastCheckUptimeMinutes";
49
50// UpdateEngine.Attempt.* metrics.
51const char kMetricAttemptNumber[] = "UpdateEngine.Attempt.Number";
52const char kMetricAttemptPayloadType[] =
53    "UpdateEngine.Attempt.PayloadType";
54const char kMetricAttemptPayloadSizeMiB[] =
55    "UpdateEngine.Attempt.PayloadSizeMiB";
56const char kMetricAttemptConnectionType[] =
57    "UpdateEngine.Attempt.ConnectionType";
58const char kMetricAttemptDurationMinutes[] =
59    "UpdateEngine.Attempt.DurationMinutes";
60const char kMetricAttemptDurationUptimeMinutes[] =
61    "UpdateEngine.Attempt.DurationUptimeMinutes";
62const char kMetricAttemptTimeSinceLastAttemptMinutes[] =
63    "UpdateEngine.Attempt.TimeSinceLastAttemptMinutes";
64const char kMetricAttemptTimeSinceLastAttemptUptimeMinutes[] =
65    "UpdateEngine.Attempt.TimeSinceLastAttemptUptimeMinutes";
66const char kMetricAttemptPayloadBytesDownloadedMiB[] =
67    "UpdateEngine.Attempt.PayloadBytesDownloadedMiB";
68const char kMetricAttemptPayloadDownloadSpeedKBps[] =
69    "UpdateEngine.Attempt.PayloadDownloadSpeedKBps";
70const char kMetricAttemptDownloadSource[] =
71    "UpdateEngine.Attempt.DownloadSource";
72const char kMetricAttemptResult[] =
73    "UpdateEngine.Attempt.Result";
74const char kMetricAttemptInternalErrorCode[] =
75    "UpdateEngine.Attempt.InternalErrorCode";
76const char kMetricAttemptDownloadErrorCode[] =
77    "UpdateEngine.Attempt.DownloadErrorCode";
78
79// UpdateEngine.SuccessfulUpdate.* metrics.
80const char kMetricSuccessfulUpdateAttemptCount[] =
81    "UpdateEngine.SuccessfulUpdate.AttemptCount";
82const char kMetricSuccessfulUpdateBytesDownloadedMiB[] =
83    "UpdateEngine.SuccessfulUpdate.BytesDownloadedMiB";
84const char kMetricSuccessfulUpdateDownloadOverheadPercentage[] =
85    "UpdateEngine.SuccessfulUpdate.DownloadOverheadPercentage";
86const char kMetricSuccessfulUpdateDownloadSourcesUsed[] =
87    "UpdateEngine.SuccessfulUpdate.DownloadSourcesUsed";
88const char kMetricSuccessfulUpdatePayloadType[] =
89    "UpdateEngine.SuccessfulUpdate.PayloadType";
90const char kMetricSuccessfulUpdatePayloadSizeMiB[] =
91    "UpdateEngine.SuccessfulUpdate.PayloadSizeMiB";
92const char kMetricSuccessfulUpdateRebootCount[] =
93    "UpdateEngine.SuccessfulUpdate.RebootCount";
94const char kMetricSuccessfulUpdateTotalDurationMinutes[] =
95    "UpdateEngine.SuccessfulUpdate.TotalDurationMinutes";
96const char kMetricSuccessfulUpdateUpdatesAbandonedCount[] =
97    "UpdateEngine.SuccessfulUpdate.UpdatesAbandonedCount";
98const char kMetricSuccessfulUpdateUrlSwitchCount[] =
99    "UpdateEngine.SuccessfulUpdate.UrlSwitchCount";
100
101// UpdateEngine.Rollback.* metric.
102const char kMetricRollbackResult[] = "UpdateEngine.Rollback.Result";
103
104// UpdateEngine.CertificateCheck.* metrics.
105const char kMetricCertificateCheckUpdateCheck[] =
106    "UpdateEngine.CertificateCheck.UpdateCheck";
107const char kMetricCertificateCheckDownload[] =
108    "UpdateEngine.CertificateCheck.Download";
109
110// UpdateEngine.* metrics.
111const char kMetricFailedUpdateCount[] = "UpdateEngine.FailedUpdateCount";
112const char kMetricInstallDateProvisioningSource[] =
113    "UpdateEngine.InstallDateProvisioningSource";
114const char kMetricTimeToRebootMinutes[] =
115    "UpdateEngine.TimeToRebootMinutes";
116
117void ReportDailyMetrics(SystemState *system_state,
118                        base::TimeDelta os_age) {
119  string metric = metrics::kMetricDailyOSAgeDays;
120  LOG(INFO) << "Uploading " << utils::FormatTimeDelta(os_age)
121            << " for metric " <<  metric;
122  system_state->metrics_lib()->SendToUMA(
123      metric,
124      static_cast<int>(os_age.InDays()),
125      0,     // min: 0 days
126      6*30,  // max: 6 months (approx)
127      50);   // num_buckets
128}
129
130void ReportUpdateCheckMetrics(SystemState *system_state,
131                              CheckResult result,
132                              CheckReaction reaction,
133                              DownloadErrorCode download_error_code) {
134  string metric;
135  int value;
136  int max_value;
137
138  if (result != metrics::CheckResult::kUnset) {
139    metric = metrics::kMetricCheckResult;
140    value = static_cast<int>(result);
141    max_value = static_cast<int>(metrics::CheckResult::kNumConstants) - 1;
142    LOG(INFO) << "Sending " << value << " for metric " << metric << " (enum)";
143    system_state->metrics_lib()->SendEnumToUMA(metric, value, max_value);
144  }
145  if (reaction != metrics::CheckReaction::kUnset) {
146    metric = metrics::kMetricCheckReaction;
147    value = static_cast<int>(reaction);
148    max_value = static_cast<int>(metrics::CheckReaction::kNumConstants) - 1;
149    LOG(INFO) << "Sending " << value << " for metric " << metric << " (enum)";
150    system_state->metrics_lib()->SendEnumToUMA(metric, value, max_value);
151  }
152  if (download_error_code != metrics::DownloadErrorCode::kUnset) {
153    metric = metrics::kMetricCheckDownloadErrorCode;
154    value = static_cast<int>(download_error_code);
155    LOG(INFO) << "Sending " << value << " for metric " << metric << " (sparse)";
156    system_state->metrics_lib()->SendSparseToUMA(metric, value);
157  }
158
159  base::TimeDelta time_since_last;
160  if (metrics_utils::WallclockDurationHelper(
161          system_state,
162          kPrefsMetricsCheckLastReportingTime,
163          &time_since_last)) {
164    metric = kMetricCheckTimeSinceLastCheckMinutes;
165    LOG(INFO) << "Sending " << utils::FormatTimeDelta(time_since_last)
166              << " for metric " << metric;
167    system_state->metrics_lib()->SendToUMA(
168        metric,
169        time_since_last.InMinutes(),
170        0,         // min: 0 min
171        30*24*60,  // max: 30 days
172        50);       // num_buckets
173  }
174
175  base::TimeDelta uptime_since_last;
176  static int64_t uptime_since_last_storage = 0;
177  if (metrics_utils::MonotonicDurationHelper(system_state,
178                                             &uptime_since_last_storage,
179                                             &uptime_since_last)) {
180    metric = kMetricCheckTimeSinceLastCheckUptimeMinutes;
181    LOG(INFO) << "Sending " << utils::FormatTimeDelta(uptime_since_last)
182              << " for metric " << metric;
183    system_state->metrics_lib()->SendToUMA(
184        metric,
185        uptime_since_last.InMinutes(),
186        0,         // min: 0 min
187        30*24*60,  // max: 30 days
188        50);       // num_buckets
189  }
190}
191
192void ReportAbnormallyTerminatedUpdateAttemptMetrics(
193    SystemState *system_state) {
194
195  string metric = metrics::kMetricAttemptResult;
196  AttemptResult attempt_result = AttemptResult::kAbnormalTermination;
197
198  LOG(INFO) << "Uploading " << static_cast<int>(attempt_result)
199            << " for metric " <<  metric;
200  system_state->metrics_lib()->SendEnumToUMA(
201      metric,
202      static_cast<int>(attempt_result),
203      static_cast<int>(AttemptResult::kNumConstants));
204}
205
206void ReportUpdateAttemptMetrics(
207    SystemState *system_state,
208    int attempt_number,
209    PayloadType payload_type,
210    base::TimeDelta duration,
211    base::TimeDelta duration_uptime,
212    int64_t payload_size,
213    int64_t payload_bytes_downloaded,
214    int64_t payload_download_speed_bps,
215    DownloadSource download_source,
216    AttemptResult attempt_result,
217    ErrorCode internal_error_code,
218    DownloadErrorCode payload_download_error_code,
219    ConnectionType connection_type) {
220  string metric;
221
222  metric = metrics::kMetricAttemptNumber;
223  LOG(INFO) << "Uploading " << attempt_number << " for metric " <<  metric;
224  system_state->metrics_lib()->SendToUMA(metric,
225                                         attempt_number,
226                                         0,    // min: 0 attempts
227                                         49,   // max: 49 attempts
228                                         50);  // num_buckets
229
230  metric = metrics::kMetricAttemptPayloadType;
231  LOG(INFO) << "Uploading " << utils::ToString(payload_type)
232            << " for metric " <<  metric;
233  system_state->metrics_lib()->SendEnumToUMA(metric,
234                                             payload_type,
235                                             kNumPayloadTypes);
236
237  metric = metrics::kMetricAttemptDurationMinutes;
238  LOG(INFO) << "Uploading " << utils::FormatTimeDelta(duration)
239            << " for metric " <<  metric;
240  system_state->metrics_lib()->SendToUMA(metric,
241                                         duration.InMinutes(),
242                                         0,         // min: 0 min
243                                         10*24*60,  // max: 10 days
244                                         50);       // num_buckets
245
246  metric = metrics::kMetricAttemptDurationUptimeMinutes;
247  LOG(INFO) << "Uploading " << utils::FormatTimeDelta(duration_uptime)
248            << " for metric " <<  metric;
249  system_state->metrics_lib()->SendToUMA(metric,
250                                         duration_uptime.InMinutes(),
251                                         0,         // min: 0 min
252                                         10*24*60,  // max: 10 days
253                                         50);       // num_buckets
254
255  metric = metrics::kMetricAttemptPayloadSizeMiB;
256  int64_t payload_size_mib = payload_size / kNumBytesInOneMiB;
257  LOG(INFO) << "Uploading " << payload_size_mib << " for metric " <<  metric;
258  system_state->metrics_lib()->SendToUMA(metric,
259                                         payload_size_mib,
260                                         0,     // min: 0 MiB
261                                         1024,  // max: 1024 MiB = 1 GiB
262                                         50);   // num_buckets
263
264  metric = metrics::kMetricAttemptPayloadBytesDownloadedMiB;
265  int64_t payload_bytes_downloaded_mib =
266       payload_bytes_downloaded / kNumBytesInOneMiB;
267  LOG(INFO) << "Uploading " << payload_bytes_downloaded_mib
268            << " for metric " <<  metric;
269  system_state->metrics_lib()->SendToUMA(metric,
270                                         payload_bytes_downloaded_mib,
271                                         0,     // min: 0 MiB
272                                         1024,  // max: 1024 MiB = 1 GiB
273                                         50);   // num_buckets
274
275  metric = metrics::kMetricAttemptPayloadDownloadSpeedKBps;
276  int64_t payload_download_speed_kbps = payload_download_speed_bps / 1000;
277  LOG(INFO) << "Uploading " << payload_download_speed_kbps
278            << " for metric " <<  metric;
279  system_state->metrics_lib()->SendToUMA(metric,
280                                         payload_download_speed_kbps,
281                                         0,        // min: 0 kB/s
282                                         10*1000,  // max: 10000 kB/s = 10 MB/s
283                                         50);      // num_buckets
284
285  metric = metrics::kMetricAttemptDownloadSource;
286  LOG(INFO) << "Uploading " << download_source
287            << " for metric " <<  metric;
288  system_state->metrics_lib()->SendEnumToUMA(metric,
289                                             download_source,
290                                             kNumDownloadSources);
291
292  metric = metrics::kMetricAttemptResult;
293  LOG(INFO) << "Uploading " << static_cast<int>(attempt_result)
294            << " for metric " <<  metric;
295  system_state->metrics_lib()->SendEnumToUMA(
296      metric,
297      static_cast<int>(attempt_result),
298      static_cast<int>(AttemptResult::kNumConstants));
299
300  if (internal_error_code != ErrorCode::kSuccess) {
301    metric = metrics::kMetricAttemptInternalErrorCode;
302    LOG(INFO) << "Uploading " << internal_error_code
303              << " for metric " <<  metric;
304    system_state->metrics_lib()->SendEnumToUMA(
305        metric,
306        static_cast<int>(internal_error_code),
307        static_cast<int>(ErrorCode::kUmaReportedMax));
308  }
309
310  if (payload_download_error_code != DownloadErrorCode::kUnset) {
311    metric = metrics::kMetricAttemptDownloadErrorCode;
312    LOG(INFO) << "Uploading " << static_cast<int>(payload_download_error_code)
313              << " for metric " <<  metric << " (sparse)";
314    system_state->metrics_lib()->SendSparseToUMA(
315        metric,
316        static_cast<int>(payload_download_error_code));
317  }
318
319  base::TimeDelta time_since_last;
320  if (metrics_utils::WallclockDurationHelper(
321          system_state,
322          kPrefsMetricsAttemptLastReportingTime,
323          &time_since_last)) {
324    metric = kMetricAttemptTimeSinceLastAttemptMinutes;
325    LOG(INFO) << "Sending " << utils::FormatTimeDelta(time_since_last)
326              << " for metric " << metric;
327    system_state->metrics_lib()->SendToUMA(
328        metric,
329        time_since_last.InMinutes(),
330        0,         // min: 0 min
331        30*24*60,  // max: 30 days
332        50);       // num_buckets
333  }
334
335  static int64_t uptime_since_last_storage = 0;
336  base::TimeDelta uptime_since_last;
337  if (metrics_utils::MonotonicDurationHelper(system_state,
338                                             &uptime_since_last_storage,
339                                             &uptime_since_last)) {
340    metric = kMetricAttemptTimeSinceLastAttemptUptimeMinutes;
341    LOG(INFO) << "Sending " << utils::FormatTimeDelta(uptime_since_last)
342              << " for metric " << metric;
343    system_state->metrics_lib()->SendToUMA(
344        metric,
345        uptime_since_last.InMinutes(),
346        0,         // min: 0 min
347        30*24*60,  // max: 30 days
348        50);       // num_buckets
349  }
350
351  metric = metrics::kMetricAttemptConnectionType;
352  LOG(INFO) << "Uploading " << static_cast<int>(connection_type)
353            << " for metric " <<  metric;
354  system_state->metrics_lib()->SendEnumToUMA(
355      metric,
356      static_cast<int>(connection_type),
357      static_cast<int>(ConnectionType::kNumConstants));
358}
359
360
361void ReportSuccessfulUpdateMetrics(
362         SystemState *system_state,
363         int attempt_count,
364         int updates_abandoned_count,
365         PayloadType payload_type,
366         int64_t payload_size,
367         int64_t num_bytes_downloaded[kNumDownloadSources],
368         int download_overhead_percentage,
369         base::TimeDelta total_duration,
370         int reboot_count,
371         int url_switch_count) {
372  string metric;
373  int64_t mbs;
374
375  metric = kMetricSuccessfulUpdatePayloadSizeMiB;
376  mbs = payload_size / kNumBytesInOneMiB;
377  LOG(INFO) << "Uploading " << mbs << " (MiBs) for metric " << metric;
378  system_state->metrics_lib()->SendToUMA(metric,
379                                         mbs,
380                                         0,     // min: 0 MiB
381                                         1024,  // max: 1024 MiB = 1 GiB
382                                         50);   // num_buckets
383
384  int64_t total_bytes = 0;
385  int download_sources_used = 0;
386  for (int i = 0; i < kNumDownloadSources + 1; i++) {
387    DownloadSource source = static_cast<DownloadSource>(i);
388
389    // Only consider this download source (and send byte counts) as
390    // having been used if we downloaded a non-trivial amount of bytes
391    // (e.g. at least 1 MiB) that contributed to the
392    // update. Otherwise we're going to end up with a lot of zero-byte
393    // events in the histogram.
394
395    metric = metrics::kMetricSuccessfulUpdateBytesDownloadedMiB;
396    if (i < kNumDownloadSources) {
397      metric += utils::ToString(source);
398      mbs = num_bytes_downloaded[i] / kNumBytesInOneMiB;
399      total_bytes += num_bytes_downloaded[i];
400      if (mbs > 0)
401        download_sources_used |= (1 << i);
402    } else {
403      mbs = total_bytes / kNumBytesInOneMiB;
404    }
405
406    if (mbs > 0) {
407      LOG(INFO) << "Uploading " << mbs << " (MiBs) for metric " << metric;
408      system_state->metrics_lib()->SendToUMA(metric,
409                                             mbs,
410                                             0,     // min: 0 MiB
411                                             1024,  // max: 1024 MiB = 1 GiB
412                                             50);   // num_buckets
413    }
414  }
415
416  metric = metrics::kMetricSuccessfulUpdateDownloadSourcesUsed;
417  LOG(INFO) << "Uploading 0x" << std::hex << download_sources_used
418            << " (bit flags) for metric " << metric;
419  system_state->metrics_lib()->SendToUMA(
420      metric,
421      download_sources_used,
422      0,                               // min
423      (1 << kNumDownloadSources) - 1,  // max
424      1 << kNumDownloadSources);       // num_buckets
425
426  metric = metrics::kMetricSuccessfulUpdateDownloadOverheadPercentage;
427  LOG(INFO) << "Uploading " << download_overhead_percentage
428            << "% for metric " << metric;
429  system_state->metrics_lib()->SendToUMA(metric,
430                                         download_overhead_percentage,
431                                         0,     // min: 0% overhead
432                                         1000,  // max: 1000% overhead
433                                         50);   // num_buckets
434
435  metric = metrics::kMetricSuccessfulUpdateUrlSwitchCount;
436  LOG(INFO) << "Uploading " << url_switch_count
437            << " (count) for metric " <<  metric;
438  system_state->metrics_lib()->SendToUMA(metric,
439                                         url_switch_count,
440                                         0,    // min: 0 URL switches
441                                         49,   // max: 49 URL switches
442                                         50);  // num_buckets
443
444  metric = metrics::kMetricSuccessfulUpdateTotalDurationMinutes;
445  LOG(INFO) << "Uploading " << utils::FormatTimeDelta(total_duration)
446            << " for metric " <<  metric;
447  system_state->metrics_lib()->SendToUMA(
448       metric,
449       static_cast<int>(total_duration.InMinutes()),
450       0,          // min: 0 min
451       365*24*60,  // max: 365 days ~= 1 year
452       50);        // num_buckets
453
454  metric = metrics::kMetricSuccessfulUpdateRebootCount;
455  LOG(INFO) << "Uploading reboot count of " << reboot_count << " for metric "
456            <<  metric;
457  system_state->metrics_lib()->SendToUMA(metric,
458                                         reboot_count,
459                                         0,    // min: 0 reboots
460                                         49,   // max: 49 reboots
461                                         50);  // num_buckets
462
463  metric = metrics::kMetricSuccessfulUpdatePayloadType;
464  system_state->metrics_lib()->SendEnumToUMA(metric,
465                                             payload_type,
466                                             kNumPayloadTypes);
467  LOG(INFO) << "Uploading " << utils::ToString(payload_type)
468            << " for metric " <<  metric;
469
470  metric = metrics::kMetricSuccessfulUpdateAttemptCount;
471  system_state->metrics_lib()->SendToUMA(metric,
472                                         attempt_count,
473                                         1,    // min: 1 attempt
474                                         50,   // max: 50 attempts
475                                         50);  // num_buckets
476  LOG(INFO) << "Uploading " << attempt_count
477            << " for metric " <<  metric;
478
479  metric = metrics::kMetricSuccessfulUpdateUpdatesAbandonedCount;
480  LOG(INFO) << "Uploading " << updates_abandoned_count
481            << " (count) for metric " <<  metric;
482  system_state->metrics_lib()->SendToUMA(metric,
483                                         updates_abandoned_count,
484                                         0,    // min: 0 counts
485                                         49,   // max: 49 counts
486                                         50);  // num_buckets
487}
488
489void ReportRollbackMetrics(SystemState *system_state,
490                           RollbackResult result) {
491  string metric;
492  int value;
493
494  metric = metrics::kMetricRollbackResult;
495  value = static_cast<int>(result);
496  LOG(INFO) << "Sending " << value << " for metric " << metric << " (enum)";
497  system_state->metrics_lib()->SendEnumToUMA(
498      metric,
499      value,
500      static_cast<int>(metrics::RollbackResult::kNumConstants));
501}
502
503void ReportCertificateCheckMetrics(SystemState* system_state,
504                                   ServerToCheck server_to_check,
505                                   CertificateCheckResult result) {
506  string metric;
507  switch (server_to_check) {
508    case ServerToCheck::kUpdate:
509      metric = kMetricCertificateCheckUpdateCheck;
510      break;
511    case ServerToCheck::kDownload:
512      metric = kMetricCertificateCheckDownload;
513      break;
514    case ServerToCheck::kNone:
515      return;
516  }
517  LOG(INFO) << "Uploading " << static_cast<int>(result) << " for metric "
518            << metric;
519  system_state->metrics_lib()->SendEnumToUMA(
520      metric, static_cast<int>(result),
521      static_cast<int>(CertificateCheckResult::kNumConstants));
522}
523
524}  // namespace metrics
525
526}  // namespace chromeos_update_engine
527