Meausre LoadTime/SaveTime of CriticalPersistedTabData/TabState

Currently the load time we have includes the time taken on the sequenced
task runner. Since CriticalPersistedTabData and TabState operations are
both performed on the sequenced task runner, we block
CriticalPersistedTabData read over the TabState read. This unfairly
biases the CriticalPersistedTabData load time metric making it larger
than it should be. It is better to compare the two independent of the
sequenced task runner.

Bug: 1166787
Change-Id: Ibc716f66cf9ec745d741f471bbd372048ef9edb9
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2627730Reviewed-by: Brian White <bcwhite@chromium.org>
Reviewed-by: Yusuf Ozuysal <yusufo@chromium.org>
Commit-Queue: David Maunder <davidjm@chromium.org>
Cr-Commit-Position: refs/heads/master@{#844140}

chrome/android/java/src/org/chromium/chrome/browser/tab/TabStateFileManager.java

@@ -4,12 +4,14 @@
 
 package org.chromium.chrome.browser.tab;
 
+import android.os.SystemClock;
 import android.util.Pair;
 
 import androidx.annotation.VisibleForTesting;
 
 import org.chromium.base.Log;
 import org.chromium.base.StreamUtil;
+import org.chromium.base.metrics.RecordHistogram;
 import org.chromium.chrome.browser.crypto.CipherFactory;
 import org.chromium.chrome.browser.version.ChromeVersionInfo;
 
@@ -64,7 +66,13 @@ public class TabStateFileManager {
         if (!file.exists()) return null;
 
         // If one of them passed, open the file input stream and read the state contents.
-        return restoreTabState(file, encrypted);
+        long startTime = SystemClock.elapsedRealtime();
+        TabState tabState = restoreTabState(file, encrypted);
+        if (tabState != null) {
+            RecordHistogram.recordTimesHistogram(
+                    "Tabs.TabState.LoadTime", SystemClock.elapsedRealtime() - startTime);
+        }
+        return tabState;
     }
 
     /**
@@ -216,6 +224,7 @@ public class TabStateFileManager {
      */
     public static void saveState(File file, TabState state, boolean encrypted) {
         if (state == null || state.contentsState == null) return;
+        long startTime = SystemClock.elapsedRealtime();
 
         // Create the byte array from contentsState before opening the FileOutputStream, in case
         // contentsState.buffer is an instance of MappedByteBuffer that is mapped to
@@ -255,6 +264,8 @@ public class TabStateFileManager {
             dataOutputStream.writeInt(
                     state.tabLaunchTypeAtCreation != null ? state.tabLaunchTypeAtCreation : -1);
             dataOutputStream.writeInt(state.rootId);
+            RecordHistogram.recordTimesHistogram(
+                    "Tabs.TabState.SaveTime", SystemClock.elapsedRealtime() - startTime);
         } catch (FileNotFoundException e) {
             Log.w(TAG, "FileNotFoundException while attempting to save TabState.");
         } catch (IOException e) {

chrome/browser/tab/java/src/org/chromium/chrome/browser/tab/state/FilePersistedTabDataStorage.java

@@ -5,6 +5,8 @@
 package org.chromium.chrome.browser.tab.state;
 
 import android.content.Context;
+import android.os.StrictMode;
+import android.os.SystemClock;
 
 import androidx.annotation.MainThread;
 import androidx.annotation.VisibleForTesting;
@@ -29,8 +31,6 @@ import java.io.IOException;
 import java.util.LinkedList;
 import java.util.Locale;
 
-import android.os.StrictMode;
-
 /**
  * {@link PersistedTabDataStorage} which uses a file for the storage
  */
@@ -207,9 +207,14 @@ public class FilePersistedTabDataStorage implements PersistedTabDataStorage {
             FileOutputStream outputStream = null;
             boolean success = false;
             try {
+                long startTime = SystemClock.elapsedRealtime();
                 outputStream = new FileOutputStream(mFile);
                 outputStream.write(mData);
                 success = true;
+                RecordHistogram.recordTimesHistogram(
+                        String.format(Locale.US, "Tabs.PersistedTabData.Storage.SaveTime.%s",
+                                getUmaTag()),
+                        SystemClock.elapsedRealtime() - startTime);
             } catch (FileNotFoundException e) {
                 Log.e(TAG,
                         String.format(Locale.ENGLISH,
@@ -332,9 +337,14 @@ public class FilePersistedTabDataStorage implements PersistedTabDataStorage {
             boolean success = false;
             byte[] res = null;
             try {
+                long startTime = SystemClock.elapsedRealtime();
                 AtomicFile atomicFile = new AtomicFile(mFile);
                 res = atomicFile.readFully();
                 success = true;
+                RecordHistogram.recordTimesHistogram(
+                        String.format(Locale.US, "Tabs.PersistedTabData.Storage.LoadTime.%s",
+                                getUmaTag()),
+                        SystemClock.elapsedRealtime() - startTime);
             } catch (FileNotFoundException e) {
                 Log.e(TAG,
                         String.format(Locale.ENGLISH,

tools/metrics/histograms/histograms_xml/tab/histograms.xml

@@ -1451,6 +1451,19 @@ reviews. Googlers can read more about this at go/gwsq-gerrit.
   </summary>
 </histogram>
 
+<histogram name="Tabs.PersistedTabData.Storage.LoadTime.File" units="ms"
+    expires_after="2022-01-13">
+  <owner>yusufo@chromium.org</owner>
+  <owner>nyquist@chromium.org</owner>
+  <owner>dtrainor@chromium.org</owner>
+  <owner>davidjm@chromium.org</owner>
+  <summary>
+    FilePersistedTabData storage stores serialized PersistedTabData (metadata
+    persisted across restarts) in a file. This metric records how long it took
+    to load the file in the event the file exists.
+  </summary>
+</histogram>
+
 <histogram name="Tabs.PersistedTabData.Storage.Restore.File"
     enum="BooleanSuccess" expires_after="2021-03-25">
   <owner>yusufo@chromium.org</owner>
@@ -1477,6 +1490,19 @@ reviews. Googlers can read more about this at go/gwsq-gerrit.
   </summary>
 </histogram>
 
+<histogram name="Tabs.PersistedTabData.Storage.SaveTime.File" units="ms"
+    expires_after="2022-01-13">
+  <owner>yusufo@chromium.org</owner>
+  <owner>nyquist@chromium.org</owner>
+  <owner>dtrainor@chromium.org</owner>
+  <owner>davidjm@chromium.org</owner>
+  <summary>
+    FilePersistedTabData storage stores serialized PersistedTabData (metadata
+    persisted across restarts) in a file. This metric records how long it took
+    to save the file in the event of a successful save.
+  </summary>
+</histogram>
+
 <histogram name="Tabs.SadTab.CrashCreated" units="tabs"
     expires_after="2021-06-01">
   <owner>sonnyrao@chromium.org</owner>
@@ -2235,6 +2261,26 @@ reviews. Googlers can read more about this at go/gwsq-gerrit.
   </summary>
 </histogram>
 
+<histogram name="Tabs.TabState.LoadTime" units="ms" expires_after="2022-01-13">
+  <owner>yusufo@chromium.org</owner>
+  <owner>nyquist@chromium.org</owner>
+  <owner>dtrainor@chromium.org</owner>
+  <owner>davidjm@chromium.org</owner>
+  <summary>
+    Time taken to load a TabState file in the event that it exists.
+  </summary>
+</histogram>
+
+<histogram name="Tabs.TabState.SaveTime" units="ms" expires_after="2022-01-13">
+  <owner>yusufo@chromium.org</owner>
+  <owner>nyquist@chromium.org</owner>
+  <owner>dtrainor@chromium.org</owner>
+  <owner>davidjm@chromium.org</owner>
+  <summary>
+    Time taken to save a TabState file in the event of a successful save.
+  </summary>
+</histogram>
+
 <histogram name="Tabs.Tasks.AverageTabGroupSize" units="tabs"
     expires_after="M85">
   <owner>yusufo@chromium.org</owner>