lacros: Add metric for lacros start time

Measure how long it takes from before the binary is launched until the
lacros binary replies with the AshChromeService mojo interface. This
is a reasonable approximation of the time until ash can start
communicating with lacros.

This will help determine if the performance in the field matches what
we see in internal benchmarks and tracing.

Bug: 1137977
Change-Id: I88210545615076a90c74d2a3f4fabf6383f20926
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2500959
Auto-Submit: James Cook <jamescook@chromium.org>
Commit-Queue: Steven Holte <holte@chromium.org>
Reviewed-by: Steven Holte <holte@chromium.org>
Reviewed-by: Erik Chen <erikchen@chromium.org>
Cr-Commit-Position: refs/heads/master@{#821979}

chrome/browser/chromeos/crosapi/browser_manager.cc

@@ -18,6 +18,7 @@
 #include "base/files/file_path.h"
 #include "base/files/file_util.h"
 #include "base/logging.h"
+#include "base/metrics/histogram_functions.h"
 #include "base/metrics/user_metrics.h"
 #include "base/metrics/user_metrics_action.h"
 #include "base/posix/eintr_wrapper.h"
@@ -353,6 +354,7 @@ void BrowserManager::StartWithLogFile(base::ScopedFD logfd) {
 
   // Create the lacros-chrome subprocess.
   base::RecordAction(base::UserMetricsAction("Lacros.Launch"));
+  lacros_launch_time_ = base::TimeTicks::Now();
   // If lacros_process_ already exists, because it does not call waitpid(2),
   // the process will never be collected.
   lacros_process_ = base::LaunchProcess(command_line, options);
@@ -372,6 +374,8 @@ void BrowserManager::OnAshChromeServiceReceiverReceived(
   ash_chrome_service_ =
       std::make_unique<AshChromeServiceImpl>(std::move(pending_receiver));
   state_ = State::RUNNING;
+  base::UmaHistogramMediumTimes("ChromeOS.Lacros.StartTime",
+                                base::TimeTicks::Now() - lacros_launch_time_);
   // Set the launch-on-login pref every time lacros-chrome successfully starts,
   // instead of once during ash-chrome shutdown, so we have the right value
   // even if ash-chrome crashes.

chrome/browser/chromeos/crosapi/browser_manager.h

@@ -13,6 +13,7 @@
 #include "base/memory/weak_ptr.h"
 #include "base/observer_list.h"
 #include "base/process/process.h"
+#include "base/time/time.h"
 #include "chrome/browser/chromeos/crosapi/browser_manager_observer.h"
 #include "chrome/browser/chromeos/crosapi/environment_provider.h"
 #include "chromeos/crosapi/mojom/crosapi.mojom.h"
@@ -185,6 +186,9 @@ class BrowserManager : public session_manager::SessionManagerObserver {
   // Called when the binary download completes.
   LoadCompleteCallback load_complete_callback_;
 
+  // Time when the lacros process was launched.
+  base::TimeTicks lacros_launch_time_;
+
   // Process handle for the lacros-chrome process.
   base::Process lacros_process_;
 

tools/metrics/histograms/histograms_xml/chromeos/histograms.xml

@@ -394,6 +394,18 @@ incoming reviews. Googlers can read more about this at go/gwsq-gerrit.
   </summary>
 </histogram>
 
+<histogram name="ChromeOS.Lacros.StartTime" units="ms"
+    expires_after="2021-10-01">
+  <owner>jamescook@chromium.org</owner>
+  <owner>erikchen@chromium.org</owner>
+  <owner>lacros-team@google.com</owner>
+  <summary>
+    Time to start the lacros binary, specifically the time between when the
+    process is launched and the mojo connection is established between ash and
+    lacros. Recorded by ash each time the lacros binary is started.
+  </summary>
+</histogram>
+
 <histogram name="ChromeOS.MachineIdRegen.AgeSeconds" units="seconds"
     expires_after="M77">
   <owner>zeuthen@chromium.org</owner>