ARC: Add BootType parameter to ReportBootProgress() in metrics.mojom

components/arc/metrics/arc_metrics_service.cc

 // Copyright 2016 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 "components/arc/metrics/arc_metrics_service.h"
 
 #include <string>
 #include <utility>
 
 #include "base/logging.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/strings/string_util.h"
 #include "chromeos/dbus/dbus_thread_manager.h"
 #include "chromeos/dbus/session_manager_client.h"
 #include "components/arc/arc_bridge_service.h"
 
+#define RECORD_ARC_UMA(suffix, elapsed_time, max_seconds)                      \

[Ilya Sherman, 2017/05/25 22:32:08]

Why are you defining this as a macro rather than a function?

[Yusuke Sato, 2017/05/25 22:48:00]

Since HISTOGRAM_POINTER_USE in base/metrics/histogram_macros_internal.h, which
UMA_HISTOGRAM_CUSTOM_TIMES is expanded to, takes a parameter called
|constant_histogram_name|, I assumed that the first parameter had to be a string
literal, but apparently I was wrong. I'm switching to a function. Thanks.

[Yusuke Sato, 2017/05/25 23:18:42]

Done. Replaced it with base::UmaHistogramCustomTimes() too.

[Ilya Sherman, 2017/05/25 23:48:57]

Yeah, it's subtle.  It needs to be a runtime-constant, but not necessarily a
string literal.

+  do {                                                                         \
+    UMA_HISTOGRAM_CUSTOM_TIMES("Arc.AndroidBootTime" suffix, (elapsed_time),   \
+                               base::TimeDelta::FromMilliseconds(1),           \
+                               base::TimeDelta::FromSeconds(max_seconds), 50); \
+  } while (false)
+
+namespace arc {
+
 namespace {
 
-const int kRequestProcessListPeriodInMinutes = 5;
-const char kArcProcessNamePrefix[] = "org.chromium.arc.";
-const char kGmsProcessNamePrefix[] = "com.google.android.gms";
-const char kBootProgressEnableScreen[] = "boot_progress_enable_screen";
+constexpr base::TimeDelta kRequestProcessListPeriod =
+    base::TimeDelta::FromMinutes(5);
+constexpr char kArcProcessNamePrefix[] = "org.chromium.arc.";
+constexpr char kGmsProcessNamePrefix[] = "com.google.android.gms";
+constexpr char kBootProgressEnableScreen[] = "boot_progress_enable_screen";
+
+std::string BootTypeToString(mojom::BootType boot_type) {
+  switch (boot_type) {
+    case mojom::BootType::UNKNOWN:
+      return "";  // for backward compatibility.
+    case mojom::BootType::FIRST_BOOT:
+      return ".FIRST_BOOT";
+    case mojom::BootType::FIRST_BOOT_AFTER_UPDATE:
+      return ".FIRST_BOOT_AFTER_UPDATE";
+    case mojom::BootType::REGULAR_BOOT:
+      return ".REGULAR_BOOT";
+  }
+  NOTREACHED();
+  return "";
+}
 
 }  // namespace
 
-namespace arc {
-
 ArcMetricsService::ArcMetricsService(ArcBridgeService* bridge_service)
     : ArcService(bridge_service),
       binding_(this),
       process_observer_(this),
       weak_ptr_factory_(this) {
   arc_bridge_service()->metrics()->AddObserver(this);
   arc_bridge_service()->process()->AddObserver(&process_observer_);
 }
 
 ArcMetricsService::~ArcMetricsService() {
@@ skipping 19 matching lines @@
 
 void ArcMetricsService::OnInstanceClosed() {
   VLOG(2) << "Close metrics service.";
   DCHECK(CalledOnValidThread());
   if (binding_.is_bound())
     binding_.Unbind();
 }
 
 void ArcMetricsService::OnProcessInstanceReady() {
   VLOG(2) << "Start updating process list.";
-  timer_.Start(FROM_HERE,
-               base::TimeDelta::FromMinutes(kRequestProcessListPeriodInMinutes),
-               this, &ArcMetricsService::RequestProcessList);
+  timer_.Start(FROM_HERE, kRequestProcessListPeriod, this,
+               &ArcMetricsService::RequestProcessList);
 }
 
 void ArcMetricsService::OnProcessInstanceClosed() {
   VLOG(2) << "Stop updating process list.";
   timer_.Stop();
 }
 
 void ArcMetricsService::RequestProcessList() {
   mojom::ProcessInstance* process_instance = ARC_GET_INSTANCE_FOR_METHOD(
       arc_bridge_service()->process(), RequestProcessList);
@@ skipping 49 matching lines @@
   if (!binding_.is_bound()) {
     mojom::MetricsHostPtr host_ptr;
     binding_.Bind(mojo::MakeRequest(&host_ptr));
     instance->Init(std::move(host_ptr));
   }
   arc_start_time_ = arc_start_time;
   VLOG(2) << "ARC start @" << arc_start_time_;
 }
 
 void ArcMetricsService::ReportBootProgress(
-    std::vector<mojom::BootProgressEventPtr> events) {
+    std::vector<mojom::BootProgressEventPtr> events,
+    mojom::BootType boot_type) {
   DCHECK(CalledOnValidThread());
+  // TODO(yusukes): Return immediately with with LOG(ERROR) when |boot_type| is
+  // UNKNOWN. Once the container is updated, we'll never see the boot type.
   int64_t arc_start_time_in_ms =
       (arc_start_time_ - base::TimeTicks()).InMilliseconds();
   for (const auto& event : events) {
     VLOG(2) << "Report boot progress event:" << event->event << "@"
             << event->uptimeMillis;
-    std::string title = "Arc." + event->event;
+    // TODO(yusukes): Always use 60.
+    const int max_seconds = (boot_type == mojom::BootType::UNKNOWN) ? 30 : 60;
+    std::string title = "Arc." + event->event + BootTypeToString(boot_type);

[Yusuke Sato, 2017/05/25 22:48:00]

This is the change for Arc.boot_progress*.

[Ilya Sherman, 2017/05/25 23:48:57]

Ah, got it.  Thanks!

     base::TimeDelta elapsed_time = base::TimeDelta::FromMilliseconds(
         event->uptimeMillis - arc_start_time_in_ms);
     // Note: This leaks memory, which is expected behavior.
     base::HistogramBase* histogram = base::Histogram::FactoryTimeGet(
         title, base::TimeDelta::FromMilliseconds(1),
-        base::TimeDelta::FromSeconds(30), 50,
+        base::TimeDelta::FromSeconds(max_seconds), 50,
         base::HistogramBase::kUmaTargetedHistogramFlag);

[Ilya Sherman, 2017/05/25 22:32:08]

nit: Could you use base::UmaHistogramCustomTimes() here?

[Yusuke Sato, 2017/05/25 23:18:42]

Done.

     histogram->AddTime(elapsed_time);
-    if (event->event.compare(kBootProgressEnableScreen) == 0)
-      UMA_HISTOGRAM_CUSTOM_TIMES("Arc.AndroidBootTime", elapsed_time,
-                                 base::TimeDelta::FromMilliseconds(1),
-                                 base::TimeDelta::FromSeconds(30), 50);
+    if (event->event.compare(kBootProgressEnableScreen) != 0)
+      continue;
+    switch (boot_type) {
+      case mojom::BootType::UNKNOWN:
+        // For backward compatibility, use "".
+        // TODO(yusukes): Replace this with NOTREACHED().
+        RECORD_ARC_UMA("", elapsed_time, max_seconds);
+        break;
+      case mojom::BootType::FIRST_BOOT:
+        RECORD_ARC_UMA(".FIRST_BOOT", elapsed_time, max_seconds);

[Ilya Sherman, 2017/05/25 22:32:08]

nit: Why ALL_CAPS?  Typically, UMA histograms use Dotted.CamelCase

[Yusuke Sato, 2017/05/25 23:18:42]

Changed it to CamelCase, thanks.

+        break;
+      case mojom::BootType::FIRST_BOOT_AFTER_UPDATE:
+        RECORD_ARC_UMA(".FIRST_BOOT_AFTER_UPDATE", elapsed_time, max_seconds);
+        break;
+      case mojom::BootType::REGULAR_BOOT:
+        RECORD_ARC_UMA(".REGULAR_BOOT", elapsed_time, max_seconds);
+        break;
+    }
   }
 }
 
 ArcMetricsService::ProcessObserver::ProcessObserver(
     ArcMetricsService* arc_metrics_service)
     : arc_metrics_service_(arc_metrics_service) {}
 
 ArcMetricsService::ProcessObserver::~ProcessObserver() = default;
 
 void ArcMetricsService::ProcessObserver::OnInstanceReady() {
   arc_metrics_service_->OnProcessInstanceReady();
 }
 
 void ArcMetricsService::ProcessObserver::OnInstanceClosed() {
   arc_metrics_service_->OnProcessInstanceClosed();
 }
 
 }  // namespace arc