Send Histogram Data for Load Times Closes mozilla-mobile#2891

ekager · Jul 13, 2018 · 1b05256 · 1b05256
1 parent f9250b5
commit 1b05256
Show file tree

Hide file tree

Showing 5 changed files with 54 additions and 74 deletions.
diff --git a/app/src/gecko/java/org/mozilla/focus/web/WebViewProvider.java b/app/src/gecko/java/org/mozilla/focus/web/WebViewProvider.java
@@ -349,7 +349,7 @@ public void onPageStop(GeckoSession session, boolean success) {
                                 isSecure = true;
                             }
 
-                            callback.onProgress(100);
+                            callback.onProgress(99);
                             callback.onPageFinished(isSecure);
                         }
                     }

diff --git a/app/src/main/java/org/mozilla/focus/fragment/BrowserFragment.java b/app/src/main/java/org/mozilla/focus/fragment/BrowserFragment.java
@@ -65,7 +65,6 @@
 import org.mozilla.focus.locale.LocaleAwareAppCompatActivity;
 import org.mozilla.focus.menu.browser.BrowserMenu;
 import org.mozilla.focus.menu.context.WebContextMenu;
-import org.mozilla.focus.observer.AverageLoadTimeObserver;
 import org.mozilla.focus.open.OpenWithFragment;
 import org.mozilla.focus.popup.PopupUtils;
 import org.mozilla.focus.session.NullSession;
@@ -323,8 +322,6 @@ public boolean onEditorAction(TextView textView, int actionId, KeyEvent keyEvent
         setBlockingEnabled(session.isBlockingEnabled());
         setShouldRequestDesktop(session.shouldRequestDesktopSite());
 
-        session.getLoading().observe(this, new AverageLoadTimeObserver(session));
-
         session.getLoading().observe(this, new NonNullObserver<Boolean>() {
             @Override
             public void onValueChanged(@NonNull Boolean loading) {

diff --git a/app/src/main/java/org/mozilla/focus/observer/AverageLoadTimeObserver.java b/app/src/main/java/org/mozilla/focus/observer/AverageLoadTimeObserver.java
diff --git a/app/src/main/java/org/mozilla/focus/session/SessionCallbackProxy.java b/app/src/main/java/org/mozilla/focus/session/SessionCallbackProxy.java
@@ -4,15 +4,22 @@
 
 package org.mozilla.focus.session;
 
+import android.os.SystemClock;
 import android.support.annotation.NonNull;
 import android.support.annotation.Nullable;
+import android.util.Log;
 import android.view.View;
 
+import org.mozilla.focus.telemetry.TelemetryWrapper;
+import org.mozilla.focus.utils.UrlUtils;
 import org.mozilla.focus.web.Download;
 import org.mozilla.focus.web.IWebView;
 
 public class SessionCallbackProxy implements IWebView.Callback {
     /* package */ static final int MINIMUM_PROGRESS = 5;
+    private static final String LOG_TAG = "SessionCallbackProxy";
+    private long startLoadTime = 0;
+    private String urlLoading;
 
     private final Session session;
     private final IWebView.Callback delegate;
@@ -24,6 +31,10 @@ public SessionCallbackProxy(Session session, IWebView.Callback delegate) {
 
     @Override
     public void onPageStarted(String url) {
+        startLoadTime = SystemClock.elapsedRealtime();
+        Log.i(LOG_TAG, "zerdatime " + startLoadTime + " - page load start");
+        urlLoading = url;
+
         session.setLoading(true);
         session.setSecure(false);
 
@@ -37,6 +48,7 @@ public void onPageStarted(String url) {
 
     @Override
     public void onPageFinished(boolean isSecure) {
+        recordEndOfLoad();
         session.setLoading(false);
         session.setSecure(isSecure);
     }
@@ -62,6 +74,11 @@ public void onProgress(int progress) {
 
     @Override
     public void onURLChanged(String url) {
+        if (!url.equals(session.getUrl().getValue())) {
+            startLoadTime = SystemClock.elapsedRealtime();
+            Log.i(LOG_TAG, "zerdatime " + startLoadTime + " - url changed to " + url + ", new page load start");
+            urlLoading = url;
+        }
         session.setUrl(url);
     }
 
@@ -124,4 +141,19 @@ public void onExitFullScreen() {
         delegate.onExitFullScreen();
     }
 
+    private void recordEndOfLoad() {
+        if (urlLoading != null && session.getUrl().getValue().equals(urlLoading)) {
+            Log.i(LOG_TAG, "Loaded page at " + session.getUrl().getValue());
+            final long endTime = SystemClock.elapsedRealtime();
+            Log.i(LOG_TAG, "zerdatime " + endTime + " - page load stop");
+            final long elapsedLoad = endTime - startLoadTime;
+            Log.i(LOG_TAG, elapsedLoad + " - elapsed load");
+            // Even internal pages take longer than 30 ms to load, let's not send any loads faster than this
+            if (elapsedLoad > 30 && !UrlUtils.isLocalizedContent(urlLoading)) {
+                Log.i(LOG_TAG, "Sent load to histogram");
+                TelemetryWrapper.addLoadToHistogram(elapsedLoad);
+            }
+        }
+    }
+
 }
diff --git a/app/src/main/java/org/mozilla/focus/telemetry/TelemetryWrapper.kt b/app/src/main/java/org/mozilla/focus/telemetry/TelemetryWrapper.kt
@@ -40,6 +40,7 @@ import org.mozilla.telemetry.storage.FileTelemetryStorage
 import java.text.SimpleDateFormat
 import java.util.Date
 import java.util.Locale
+import java.util.Arrays
 
 @Suppress(
         // Yes, this a large class with a lot of functions. But it's very simple and still easy to read.
@@ -165,7 +166,7 @@ object TelemetryWrapper {
         val SOURCE = "source"
         val SUCCESS = "success"
         val ERROR_CODE = "error_code"
-        val AVERAGE = "average"
+        val HISTOGRAM = "histogram"
     }
 
     enum class BrowserContextMenuValue {
@@ -288,19 +289,24 @@ object TelemetryWrapper {
         TelemetryEvent.create(Category.ACTION, Method.FOREGROUND, Object.APP).queue()
     }
 
-    private var numLoads: Int = 0
-    private var averageTime: Double = 0.0
+    private var histogram = IntArray(200)
 
     @JvmStatic
-    fun addLoadToAverage(newLoadTime: Long) {
-        numLoads++
-        averageTime += (newLoadTime - averageTime) / numLoads
-    }
+    fun addLoadToHistogram(newLoadTime: Long) {
+        // Histogram broken into 200 100ms buckets, we record num events in each bucket
+        var histogramLoadIndex = (newLoadTime / 100).toInt()
 
-    @JvmStatic
-    private fun resetAverageLoad() {
-        numLoads = 0
-        averageTime = 0.0
+        // Maxed out above 20,000ms, put in last bucket
+        if (histogramLoadIndex > 198) {
+            histogramLoadIndex = 199
+        }
+
+        // I don't know why this would happen but we don't want to go out of index
+        if (histogramLoadIndex < 0) {
+            histogramLoadIndex = 0
+        }
+
+        histogram[histogramLoadIndex]++
     }
 
     @JvmStatic
@@ -320,11 +326,10 @@ object TelemetryWrapper {
     fun stopSession() {
         TelemetryHolder.get().recordSessionEnd()
 
-        if (numLoads > 0) {
-            TelemetryEvent.create(Category.ACTION, Method.FOREGROUND, Object.BROWSER)
-                    .extra(Extra.AVERAGE, averageTime.toString()).queue()
-            resetAverageLoad()
-        }
+        TelemetryEvent.create(Category.ACTION, Method.FOREGROUND, Object.BROWSER)
+                .extra(Extra.HISTOGRAM, Arrays.toString(histogram)).queue()
+        // Clear histogram after queueing it
+        histogram = IntArray(200)
 
         TelemetryEvent.create(Category.ACTION, Method.BACKGROUND, Object.APP).queue()
     }