Measure time spent in SharedPrefs-loading StrictMode violations.

BUG=580262,562189

Committed: https://crrev.com/5db5d9e5815c64ba4bc93fda27115c542df35316
Cr-Commit-Position: refs/heads/master@{#371573}

Review URL: https://codereview.chromium.org/1618973002

Cr-Commit-Position: refs/heads/master@{#371623}

chrome/android/java/src/org/chromium/chrome/browser/tabmodel/document/DocumentTabModelImpl.java

@@ -10,6 +10,7 @@ import android.content.Intent;
 import android.content.SharedPreferences;
 import android.os.AsyncTask;
 import android.os.StrictMode;
+import android.os.SystemClock;
 import android.text.TextUtils;
 import android.util.Log;
 import android.util.Pair;
@@ -21,6 +22,7 @@ import org.chromium.base.ApplicationStatus;
 import org.chromium.base.ObserverList;
 import org.chromium.base.ThreadUtils;
 import org.chromium.base.VisibleForTesting;
+import org.chromium.base.metrics.RecordHistogram;
 import org.chromium.chrome.browser.TabState;
 import org.chromium.chrome.browser.document.DocumentActivity;
 import org.chromium.chrome.browser.document.DocumentMetricIds;
@@ -43,6 +45,7 @@ import java.util.ArrayList;
 import java.util.HashSet;
 import java.util.List;
 import java.util.Set;
+import java.util.concurrent.TimeUnit;
 
 /**
  * Maintains a list of Tabs displayed when Chrome is running in document-mode.
@@ -136,6 +139,9 @@ public class DocumentTabModelImpl extends TabModelJniBridge implements DocumentT
     /** ID of the last tab that was shown to the user. */
     private int mLastShownTabId = Tab.INVALID_TAB_ID;
 
+    /** Initial load time for shared preferences */
+    private long mSharedPrefsLoadTime;
+
     /**
      * Pre-load shared prefs to avoid being blocked on the
      * disk access async task in the future.
@@ -170,10 +176,12 @@ public class DocumentTabModelImpl extends TabModelJniBridge implements DocumentT
         mInitializationObservers = new ObserverList<InitializationObserver>();
         mObservers = new ObserverList<TabModelObserver>();
 
+        long time = SystemClock.elapsedRealtime();
         SharedPreferences prefs = mContext.getSharedPreferences(PREF_PACKAGE, Context.MODE_PRIVATE);
         mLastShownTabId = prefs.getInt(
                 isIncognito() ? PREF_LAST_SHOWN_TAB_ID_INCOGNITO : PREF_LAST_SHOWN_TAB_ID_REGULAR,
                 Tab.INVALID_TAB_ID);
+        mSharedPrefsLoadTime = SystemClock.elapsedRealtime() - time;
 
         // Restore the tab list.
         setCurrentState(STATE_READ_RECENT_TASKS_START);
@@ -186,6 +194,11 @@ public class DocumentTabModelImpl extends TabModelJniBridge implements DocumentT
     public void initializeNative() {
         if (!isNativeInitialized()) super.initializeNative();
         deserializeTabStatesAsync();
+
+        if (isNativeInitialized()) {
+            RecordHistogram.recordTimesHistogram("Android.StrictMode.DocumentModeSharedPrefs",
+                    mSharedPrefsLoadTime, TimeUnit.MILLISECONDS);
+        }
     }
 
     public StorageDelegate getStorageDelegate() {

chrome/android/java/src/org/chromium/chrome/browser/webapps/ActivityAssigner.java

@@ -6,15 +6,18 @@ package org.chromium.chrome.browser.webapps;
 
 import android.content.Context;
 import android.content.SharedPreferences;
+import android.os.SystemClock;
 import android.util.Log;
 
 import org.chromium.base.ThreadUtils;
 import org.chromium.base.VisibleForTesting;
+import org.chromium.base.metrics.RecordHistogram;
 
 import java.util.ArrayList;
 import java.util.HashSet;
 import java.util.List;
 import java.util.Set;
+import java.util.concurrent.TimeUnit;
 
 /**
  * Manages a rotating LRU buffer of WebappActivities to assign webapps to.
@@ -214,7 +217,14 @@ public class ActivityAssigner {
         // been corrupted somehow, just discard the whole map.
         SharedPreferences prefs = mContext.getSharedPreferences(PREF_PACKAGE, Context.MODE_PRIVATE);
         try {
+            long time = SystemClock.elapsedRealtime();
             final int numSavedEntries = prefs.getInt(PREF_NUM_SAVED_ENTRIES, 0);
+            try {
+                RecordHistogram.recordTimesHistogram("Android.StrictMode.WebappSharedPrefs",
+                        SystemClock.elapsedRealtime() - time, TimeUnit.MILLISECONDS);
+            } catch (UnsatisfiedLinkError error) {
+                // Intentionally ignored - it's ok to miss recording the metric occasionally.
+            }
             if (numSavedEntries <= NUM_WEBAPP_ACTIVITIES) {
                 for (int i = 0; i < numSavedEntries; ++i) {
                     String currentActivityIndexPref = PREF_ACTIVITY_INDEX + i;

chrome/android/javatests/src/org/chromium/chrome/browser/tabmodel/document/DocumentTabModelImplTest.java

@@ -10,6 +10,7 @@ import android.test.suitebuilder.annotation.SmallTest;
 
 import org.chromium.base.CommandLine;
 import org.chromium.base.ThreadUtils;
+import org.chromium.base.metrics.RecordHistogram;
 import org.chromium.base.test.util.AdvancedMockContext;
 import org.chromium.chrome.browser.tab.Tab;
 import org.chromium.chrome.browser.tabmodel.TabModel;
@@ -82,6 +83,7 @@ public class DocumentTabModelImplTest extends NativeLibraryTestBase {
     @Override
     protected void setUp() throws Exception {
         super.setUp();
+        RecordHistogram.disableForTests();
         CommandLine.init(null);
         loadNativeLibraryAndInitBrowserProcess();
 

chrome/android/javatests/src/org/chromium/chrome/browser/webapps/ActivityAssignerTest.java

@@ -8,6 +8,7 @@ import android.test.InstrumentationTestCase;
 import android.test.UiThreadTest;
 import android.test.suitebuilder.annotation.SmallTest;
 
+import org.chromium.base.metrics.RecordHistogram;
 import org.chromium.base.test.util.AdvancedMockContext;
 import org.chromium.base.test.util.Feature;
 
@@ -28,6 +29,7 @@ public class ActivityAssignerTest extends InstrumentationTestCase {
     @Override
     protected void setUp() throws Exception {
         super.setUp();
+        RecordHistogram.disableForTests();
         mContext = new AdvancedMockContext();
         mPreferences = new HashMap<String, Object>();
         mContext.addSharedPreferences(ActivityAssigner.PREF_PACKAGE, mPreferences);
@@ -159,4 +161,4 @@ public class ActivityAssignerTest extends InstrumentationTestCase {
             assertTrue(assignedActivities.contains(i));
         }
     }
-}
\ No newline at end of file
+}

tools/metrics/histograms/histograms.xml

@@ -312,6 +312,15 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   </summary>
 </histogram>
 
+<histogram name="Android.StrictMode.DocumentModeSharedPrefs" units="ms">
+  <owner>hartmanng@chromium.org</owner>
+  <owner>yfriedman@chromium.org</owner>
+  <summary>
+    Measures the amount of time due to a StrictMode violation from fetching the
+    DocumentMode shared preferences file.
+  </summary>
+</histogram>
+
 <histogram name="Android.StrictMode.DocumentTabStateLoad" units="ms">
   <owner>wnwen@chromium.org</owner>
   <owner>yfriedman@chromium.org</owner>
@@ -384,6 +393,15 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   </summary>
 </histogram>
 
+<histogram name="Android.StrictMode.WebappSharedPrefs" units="ms">
+  <owner>hartmanng@chromium.org</owner>
+  <owner>yfriedman@chromium.org</owner>
+  <summary>
+    Measures the amount of time due to a StrictMode violation from fetching the
+    Webapp shared preferences file.
+  </summary>
+</histogram>
+
 <histogram name="AndroidTabCloseUndo.Toast"
     enum="AndroidTabCloseUndoToastEvent">
   <owner>dtrainor@chromium.org</owner>