Record latency histograms for custom tabs dynamic modules.

Bug: 853791
Change-Id: I3349c450d8b285bcfdea69e6342350941d121353
Reviewed-on: https://chromium-review.googlesource.com/1120503
Commit-Queue: Michael van Ouwerkerk <mvanouwerkerk@chromium.org>
Reviewed-by: Robert Kaplow <rkaplow@chromium.org>
Reviewed-by: Benoit L <lizeb@chromium.org>
Cr-Commit-Position: refs/heads/master@{#572307}

chrome/android/java/src/org/chromium/chrome/browser/customtabs/CustomTabActivity.java

@@ -62,6 +62,7 @@ import org.chromium.chrome.browser.compositor.layouts.LayoutManager;
 import org.chromium.chrome.browser.customtabs.dynamicmodule.ActivityDelegate;
 import org.chromium.chrome.browser.customtabs.dynamicmodule.ActivityHostImpl;
 import org.chromium.chrome.browser.customtabs.dynamicmodule.ModuleEntryPoint;
+import org.chromium.chrome.browser.customtabs.dynamicmodule.ModuleMetrics;
 import org.chromium.chrome.browser.datausage.DataUseTabUIManager;
 import org.chromium.chrome.browser.externalauth.ExternalAuthUtils;
 import org.chromium.chrome.browser.externalnav.ExternalNavigationDelegateImpl;
@@ -371,7 +372,9 @@ public class CustomTabActivity extends ChromeActivity {
         ModuleEntryPoint entryPoint = mConnection.loadModule(packageName, className);
         if (entryPoint == null) return;
 
+        long createActivityDelegateStartTime = ModuleMetrics.now();
         mActivityDelegate = entryPoint.createActivityDelegate(new ActivityHostImpl(this));
+        ModuleMetrics.recordCreateActivityDelegateTime(createActivityDelegateStartTime);
         mActivityDelegate.onCreate(getSavedInstanceState());
     }
 

chrome/android/java/src/org/chromium/chrome/browser/customtabs/dynamicmodule/ModuleLoader.java

@@ -36,9 +36,13 @@ public final class ModuleLoader {
         if (moduleContext == null) return null;
 
         try {
+            long entryPointLoadClassStartTime = ModuleMetrics.now();
             Class<?> clazz = moduleContext.getClassLoader().loadClass(className);
+            ModuleMetrics.recordLoadClassTime(entryPointLoadClassStartTime);
 
+            long entryPointNewInstanceStartTime = ModuleMetrics.now();
             IBinder binder = (IBinder) clazz.newInstance();
+            ModuleMetrics.recordEntryPointNewInstanceTime(entryPointNewInstanceStartTime);
 
             ModuleHostImpl moduleHost = new ModuleHostImpl(applicationContext, moduleContext);
             ModuleEntryPoint entryPoint =
@@ -67,8 +71,10 @@ public final class ModuleLoader {
         try {
             // The flags Context.CONTEXT_INCLUDE_CODE and Context.CONTEXT_IGNORE_SECURITY are
             // needed to be able to load classes via the classloader of the returned context.
+            long createPackageContextStartTime = ModuleMetrics.now();
             Context moduleContext = applicationContext.createPackageContext(
                     packageName, Context.CONTEXT_INCLUDE_CODE | Context.CONTEXT_IGNORE_SECURITY);
+            ModuleMetrics.recordCreatePackageContextTime(createPackageContextStartTime);
             return moduleContext;
         } catch (PackageManager.NameNotFoundException e) {
             Log.e(TAG, "Could not create package context for %s", packageName, e);

chrome/android/java/src/org/chromium/chrome/browser/customtabs/dynamicmodule/ModuleMetrics.java

+// Copyright 2018 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.
+
+package org.chromium.chrome.browser.customtabs.dynamicmodule;
+
+import android.os.SystemClock;
+
+import org.chromium.base.metrics.RecordHistogram;
+
+import java.util.concurrent.TimeUnit;
+
+/**
+ * Records metrics related to custom tabs dynamic modules.
+ */
+public final class ModuleMetrics {
+    private ModuleMetrics() {}
+
+    /**
+     * SystemClock.uptimeMillis() is used here as it uses the same system call as all the native
+     * side of Chrome, and this is the same clock used for page load metrics.
+     *
+     * @return Milliseconds since boot, not counting time spent in deep sleep.
+     */
+    public static long now() {
+        return SystemClock.uptimeMillis();
+    }
+
+    public static void recordCreateActivityDelegateTime(long startTime) {
+        RecordHistogram.recordMediumTimesHistogram(
+                "CustomTabs.DynamicModule.CreateActivityDelegateTime", now() - startTime,
+                TimeUnit.MILLISECONDS);
+    }
+
+    public static void recordCreatePackageContextTime(long startTime) {
+        RecordHistogram.recordMediumTimesHistogram(
+                "CustomTabs.DynamicModule.CreatePackageContextTime", now() - startTime,
+                TimeUnit.MILLISECONDS);
+    }
+
+    public static void recordLoadClassTime(long startTime) {
+        RecordHistogram.recordMediumTimesHistogram(
+                "CustomTabs.DynamicModule.EntryPointLoadClassTime", now() - startTime,
+                TimeUnit.MILLISECONDS);
+    }
+
+    public static void recordEntryPointNewInstanceTime(long startTime) {
+        RecordHistogram.recordMediumTimesHistogram(
+                "CustomTabs.DynamicModule.EntryPointNewInstanceTime", now() - startTime,
+                TimeUnit.MILLISECONDS);
+    }
+}

chrome/android/java_sources.gni

@@ -383,6 +383,7 @@ chrome_java_sources = [
   "java/src/org/chromium/chrome/browser/customtabs/dynamicmodule/ModuleEntryPoint.java",
   "java/src/org/chromium/chrome/browser/customtabs/dynamicmodule/ModuleHostImpl.java",
   "java/src/org/chromium/chrome/browser/customtabs/dynamicmodule/ModuleLoader.java",
+  "java/src/org/chromium/chrome/browser/customtabs/dynamicmodule/ModuleMetrics.java",
   "java/src/org/chromium/chrome/browser/customtabs/dynamicmodule/ObjectWrapper.java",
   "java/src/org/chromium/chrome/browser/database/SQLiteCursor.java",
   "java/src/org/chromium/chrome/browser/datausage/DataUseTabUIManager.java",

tools/metrics/histograms/histograms.xml

@@ -14896,6 +14896,39 @@ uploading your change for review.
   </summary>
 </histogram>
 
+<histogram name="CustomTabs.DynamicModule.CreateActivityDelegateTime"
+    units="ms">
+  <owner>mvanouwerkerk@chromium.org</owner>
+  <summary>
+    Time to create an activity delegate for a custom tabs dynamic module.
+    Android only.
+  </summary>
+</histogram>
+
+<histogram name="CustomTabs.DynamicModule.CreatePackageContextTime" units="ms">
+  <owner>mvanouwerkerk@chromium.org</owner>
+  <summary>
+    Time to create the package context for a custom tabs dynamic module. Android
+    only.
+  </summary>
+</histogram>
+
+<histogram name="CustomTabs.DynamicModule.EntryPointLoadClassTime" units="ms">
+  <owner>mvanouwerkerk@chromium.org</owner>
+  <summary>
+    Time to load the entry point class for a custom tabs dynamic module. Android
+    only.
+  </summary>
+</histogram>
+
+<histogram name="CustomTabs.DynamicModule.EntryPointNewInstanceTime" units="ms">
+  <owner>mvanouwerkerk@chromium.org</owner>
+  <summary>
+    Time to instantiate the entry point class for a custom tabs dynamic module.
+    Android only.
+  </summary>
+</histogram>
+
 <histogram name="CustomTabs.IntentToFirstCommitNavigationTime" units="ms">
   <obsolete>
     Deprecated 10/2016 in favor of .IntentToFirstCommitNavigationTime2.*.