Bug 1363845 - Talos pageloader changes to support 'time to first non-blank paint' measurement for tp6; r=jmaher

MozReview-Commit-ID: 4FX1uyMqtLh

--HG--
extra : rebase_source : d55891ea083b53de427947ab5c28ca967a699391

testing/talos/talos/cmdline.py

@@ -125,7 +125,7 @@ def create_parser(mach_interface=False):
                  'path and name of the mitmdump file to playback')
     add_arg('--mitmdumpPath',
             help="Path to mitmproxy's mitmdump playback tool")
-    add_arg("--firstNonBlankPaint", action='store_true', dest="first_non_blank_paint",
+    add_arg("--firstNonBlankPaint", action='store_true', dest="fnbpaint",
             help="Wait for firstNonBlankPaint event before recording the time")
     add_arg('--webServer', dest='webserver',
             help="DEPRECATED")

testing/talos/talos/config.py

@@ -39,6 +39,7 @@ DEFAULTS = dict(
         tpchrome=True,
         tpcycles=10,
         tpmozafterpaint=False,
+        fnbpaint=False,
         firstpaint=False,
         userready=False,
         testeventmap=[],
@@ -207,6 +208,7 @@ GLOBAL_OVERRIDES = (
     'tpmanifest',
     'tptimeout',
     'tpmozafterpaint',
+    'fnbpaint',
     'firstpaint',
     'userready',
 )
@@ -361,6 +363,7 @@ def get_test(config, global_overrides, counters, test_instance):
     mozAfterPaint = getattr(test_instance, 'tpmozafterpaint', None)
     firstPaint = getattr(test_instance, 'firstpaint', None)
     userReady = getattr(test_instance, 'userready', None)
+    firstNonBlankPaint = getattr(test_instance, 'fnbpaint', None)
 
     test_instance.update(**global_overrides)
 
@@ -368,6 +371,8 @@ def get_test(config, global_overrides, counters, test_instance):
     # so check for None
     if mozAfterPaint is not None:
         test_instance.tpmozafterpaint = mozAfterPaint
+    if firstNonBlankPaint is not None:
+        test_instance.fnbpaint = firstNonBlankPaint
     if firstPaint is not None:
         test_instance.firstpaint = firstPaint
     if userReady is not None:

testing/talos/talos/pageloader/chrome/pageloader.js

@@ -43,6 +43,7 @@ var forceCC = true;
 var reportRSS = true;
 
 var useMozAfterPaint = false;
+var useFNBPaint = false;
 var gPaintWindow = window;
 var gPaintListener = false;
 var loadNoCache = false;
@@ -149,6 +150,7 @@ function plInit() {
     if (args.timeout) timeout = parseInt(args.timeout);
     if (args.delay) delay = parseInt(args.delay);
     if (args.mozafterpaint) useMozAfterPaint = true;
+    if (args.fnbpaint) useFNBPaint = true;
     if (args.rss) reportRSS = true;
     if (args.loadnocache) loadNoCache = true;
     if (args.scrolltest) scrollTest = true;
@@ -262,11 +264,32 @@ function plInit() {
                     content.selectedBrowser.getAttribute("remote") == "true")
 
         // Load the frame script for e10s / IPC message support
-        if (gUseE10S) {
         let contentScript = "data:,function _contentLoadHandler(e) { " +
           "  if (e.originalTarget.defaultView == content) { " +
           "    content.wrappedJSObject.tpRecordTime = function(t, s, n) { sendAsyncMessage('PageLoader:RecordTime', { time: t, startTime: s, testName: n }); }; ";
-          if (useMozAfterPaint) {
+        if (useFNBPaint) {
+          contentScript += "" +
+          "var gRetryCounter = 0; " +
+          "function _contentFNBPaintHandler() { " +
+          "  x = content.window.performance.timing.timeToNonBlankPaint; " +
+          "  if (typeof x == 'undefined') { " +
+          "    sendAsyncMessage('PageLoader:FNBPaintError', {}); " +
+          "  } " +
+          "  if (x > 0) { " +
+          "    sendAsyncMessage('PageLoader:LoadEvent', { 'fnbpaint': x }); " +
+          "  } else { " +
+          "    gRetryCounter += 1; " +
+          "    if (gRetryCounter <= 10) { " +
+          "      dump('fnbpaint is not yet available (0), retry number ' + gRetryCounter + '...\\n'); " +
+          "      content.setTimeout(_contentFNBPaintHandler, 100); " +
+          "    } else { " +
+          "      dump('unable to get a value for fnbpaint after ' + gRetryCounter + ' retries\\n'); " +
+          "      sendAsyncMessage('PageLoader:FNBPaintError', {}); " +
+          "    } " +
+          "  } " +
+          "}; " +
+          "content.setTimeout(_contentFNBPaintHandler, 0); ";
+        } else if (useMozAfterPaint) {
           contentScript += "" +
           "function _contentPaintHandler() { " +
           "  var utils = content.QueryInterface(Components.interfaces.nsIInterfaceRequestor).getInterface(Components.interfaces.nsIDOMWindowUtils); " +
@@ -290,8 +313,7 @@ function plInit() {
         content.selectedBrowser.messageManager.loadFrameScript(contentScript, false, true);
         content.selectedBrowser.messageManager.loadFrameScript("chrome://pageloader/content/talos-content.js", false);
         content.selectedBrowser.messageManager.loadFrameScript("chrome://pageloader/content/tscroll.js", false, true);
-          content.selectedBrowser.messageManager.loadFrameScript("chrome://talos-powers-content/content/TalosContentProfiler.js", false, true);
+        content.selectedBrowser.messageManager.loadFrameScript("chrome://pageloader/content/Profiler.js", false, true);
-        }
 
         if (reportRSS) {
           initializeMemoryCollector(plLoadPage, 100);
@@ -316,6 +338,7 @@ var ContentListener = {
   receiveMessage(message) {
     switch (message.name) {
       case "PageLoader:LoadEvent": return plLoadHandlerMessage(message);
+      case "PageLoader:FNBPaintError": return plFNBPaintErrorMessage(message);
       case "PageLoader:RecordTime": return plRecordTimeMessage(message);
     }
     return undefined;
@@ -342,44 +365,21 @@ function plLoadPage() {
     removeLastAddedMsgListener = null;
   }
 
-  if ((plPageFlags() & TEST_DOES_OWN_TIMING) && !gUseE10S) {
+  // messages to watch for page load
-    // if the page does its own timing, use a capturing handler
-    // to make sure that we can set up the function for content to call
-
-    content.addEventListener("load", plLoadHandlerCapturing, true);
-    removeLastAddedListener = function() {
-      content.removeEventListener("load", plLoadHandlerCapturing, true);
-      if (useMozAfterPaint) {
-        content.removeEventListener("MozAfterPaint", plPaintedCapturing, true);
-        gPaintListener = false;
-      }
-    };
-  } else if (!gUseE10S) {
-    // if the page doesn't do its own timing, use a bubbling handler
-    // to make sure that we're called after the page's own onload() handling
-
-    // XXX we use a capturing event here too -- load events don't bubble up
-    // to the <browser> element.  See bug 390263.
-    content.addEventListener("load", plLoadHandler, true);
-    removeLastAddedListener = function() {
-      content.removeEventListener("load", plLoadHandler, true);
-      if (useMozAfterPaint) {
-        gPaintWindow.removeEventListener("MozAfterPaint", plPainted, true);
-        gPaintListener = false;
-      }
-    };
-  }
-
-  // If the test browser is remote (e10s / IPC) we need to use messages to watch for page load
-  if (gUseE10S) {
   let mm = content.selectedBrowser.messageManager;
   mm.addMessageListener("PageLoader:LoadEvent", ContentListener);
   mm.addMessageListener("PageLoader:RecordTime", ContentListener);
+  if (useFNBPaint) {
+    mm.addMessageListener("PageLoader:FNBPaintError", ContentListener);
+  }
+
   removeLastAddedMsgListener = function() {
     mm.removeMessageListener("PageLoader:LoadEvent", ContentListener);
     mm.removeMessageListener("PageLoader:RecordTime", ContentListener);
-    };
+    if (useFNBPaint) {
+      mm.removeMessageListener("PageLoader:FNBPaintError", ContentListener);
     }
+  };
 
   failTimeout.register(loadFail, timeout);
 
@@ -653,11 +653,18 @@ function plPainted() {
   _loadHandler();
 }
 
-function _loadHandler() {
+function _loadHandler(fnbpaint = 0) {
   failTimeout.clear();
+  var end_time = 0;
 
-  var end_time = Date.now();
+  if (fnbpaint !== 0) {
-  var time = (end_time - start_time);
+    // window.performance.timing.timeToNonBlankPaint is a timestamp
+    end_time = fnbpaint;
+  } else {
+    end_time = Date.now();
+  }
+
+  var duration = (end_time - start_time);
 
   TalosParentProfiler.pause("Bubbling load handler fired.");
 
@@ -668,7 +675,7 @@ function _loadHandler() {
     plStop(true);
   }
 
-  plRecordTime(time);
+  plRecordTime(duration);
 
   if (doRenderTest)
     runRenderTest();
@@ -677,7 +684,11 @@ function _loadHandler() {
 }
 
 // the core handler for remote (e10s) browser
-function plLoadHandlerMessage() {
+function plLoadHandlerMessage(message) {
+  let fnbpaint = 0;
+  if (message.json.fnbpaint !== undefined) {
+    fnbpaint = message.json.fnbpaint;
+  }
   failTimeout.clear();
 
   if ((plPageFlags() & EXECUTE_SCROLL_TEST)) {
@@ -705,7 +716,7 @@ function plLoadHandlerMessage() {
       plNextPage();
     }
   } else {
-    _loadHandler();
+    _loadHandler(fnbpaint);
   }
 }
 
@@ -721,6 +732,12 @@ function plRecordTimeMessage(message) {
   _loadHandlerCapturing();
 }
 
+// error retrieving fnbpaint
+function plFNBPaintErrorMessage(message) {
+  dumpLine("Abort: firstNonBlankPaint value is not available after loading the page");
+  plStop(true);
+}
+
 function runRenderTest() {
   const redrawsPerSample = 500;
 
@@ -778,17 +795,21 @@ function plStopAll(force) {
   if (content) {
     content.removeEventListener("load", plLoadHandlerCapturing, true);
     content.removeEventListener("load", plLoadHandler, true);
-    if (useMozAfterPaint)
+
+    if (useMozAfterPaint) {
       content.removeEventListener("MozAfterPaint", plPaintedCapturing, true);
       content.removeEventListener("MozAfterPaint", plPainted, true);
+    }
 
-    if (gUseE10S) {
     let mm = content.selectedBrowser.messageManager;
     mm.removeMessageListener("PageLoader:LoadEvent", ContentListener);
     mm.removeMessageListener("PageLoader:RecordTime", ContentListener);
 
-      mm.loadFrameScript("data:,removeEventListener('load', _contentLoadHandler, true);", false, true);
+    if (useFNBPaint) {
+      mm.removeMessageListener("PageLoader:FNBPaintError", ContentListener);
     }
+
+    mm.loadFrameScript("data:,removeEventListener('load', _contentLoadHandler, true);", false, true);
   }
 
   if (MozillaFileLogger && MozillaFileLogger._foStream)

testing/talos/talos/pageloader/components/tp-cmdline.js

@@ -97,6 +97,7 @@ PageLoaderCmdLineHandler.prototype =
       args.delay = cmdLine.handleFlagWithParam("tpdelay", false);
       args.noForceCC = cmdLine.handleFlag("tpnoforcecc", false);
       args.mozafterpaint = cmdLine.handleFlag("tpmozafterpaint", false);
+      args.fnbpaint = cmdLine.handleFlag("fnbpaint", false);
       args.loadnocache = cmdLine.handleFlag("tploadnocache", false);
       args.scrolltest = cmdLine.handleFlag("tpscrolltest", false);
       args.disableE10s = cmdLine.handleFlag("tpdisable_e10s", false);
@@ -133,6 +134,7 @@ PageLoaderCmdLineHandler.prototype =
   "  -tpdelay               Amount of time to wait between each pageload\n" +
   "  -tpnoforcecc           Don't force cycle collection between each pageload\n" +
   "  -tpmozafterpaint       Measure Time after recieving MozAfterPaint event instead of load event\n" +
+  "  -fnbpaint  Measure time after a first non-blank paint has occurred\n" +
   "  -tpscrolltest          Unknown\n" +
   "  -tpdisable_e10s        disable pageloader e10s code path\n" +
   "  -rss                   Dump RSS after each page is loaded\n"

testing/talos/talos/pageloader/install.rdf

@@ -4,7 +4,7 @@
      xmlns:em="http://www.mozilla.org/2004/em-rdf#">
   <Description about="urn:mozilla:install-manifest">
     <em:id>pageloader@mozilla.org</em:id>
-    <em:version>1.0.19</em:version>
+    <em:version>1.0.22</em:version>
     <em:targetApplication>
       <Description>
         <em:id>{ec8030f7-c20a-464f-9b0e-13a3a9e97384}</em:id>

testing/talos/talos/run_tests.py

@@ -61,11 +61,12 @@ def buildCommandLine(test):
     url = ['-tp', test['tpmanifest']]
     CLI_bool_options = ['tpchrome', 'tpmozafterpaint', 'tpdisable_e10s',
                         'tpnoisy', 'rss', 'tprender', 'tploadnocache',
-                        'tpscrolltest']
+                        'tpscrolltest', 'fnbpaint']
     CLI_options = ['tpcycles', 'tppagecycles', 'tpdelay', 'tptimeout']
     for key in CLI_bool_options:
         if test.get(key):
             url.append('-%s' % key)
+
     for key in CLI_options:
         value = test.get(key)
         if value:
@@ -122,6 +123,11 @@ def run_tests(config, browser_config):
 
     browser_config['preferences']['extensions.allow-non-mpc-extensions'] = True
 
+    # if using firstNonBlankPaint, must turn on pref for it
+    if test.get('fnbpaint', False):
+        LOG.info("Using firstNonBlankPaint, so turning on pref for it")
+        browser_config['preferences']['dom.performance.time_to_non_blank_paint.enabled'] = True
+
     # set defaults
     testdate = config.get('testdate', '')
 
@@ -222,9 +228,6 @@ def run_tests(config, browser_config):
                                          browser_config['browser_path'],
                                          str(scripts_path))
 
-    if config.get('first_non_blank_paint', False):
-        browser_config['firstNonBlankPaint'] = True
-
     testname = None
     # run the tests
     timer = utils.Timer()

testing/talos/talos/test.py

@@ -104,6 +104,7 @@ class TsBase(Test):
         'xperf_user_providers',
         'xperf_stackwalk',
         'tpmozafterpaint',
+        'fnbpaint',
         'firstpaint',
         'userready',
         'testeventmap',
@@ -233,7 +234,7 @@ class PageloaderTest(Test):
     cycles = None
     timeout = None
     keys = ['tpmanifest', 'tpcycles', 'tppagecycles', 'tprender', 'tpchrome',
-            'tpmozafterpaint', 'tploadnocache', 'firstpaint', 'userready',
+            'tpmozafterpaint', 'fnbpaint', 'tploadnocache', 'firstpaint', 'userready',
             'testeventmap', 'base_vs_ref', 'rss', 'mainthread', 'resolution', 'cycles',
             'gecko_profile', 'gecko_profile_interval', 'gecko_profile_entries',
             'tptimeout', 'win_counters', 'w7_counters', 'linux_counters', 'mac_counters',
@@ -254,6 +255,7 @@ class QuantumPageloadTest(PageloaderTest):
     filters = filter.ignore_first.prepare(5) + filter.median.prepare()
     unit = 'ms'
     lower_is_better = True
+    fnbpaint = True
 
 
 @register_test()
@@ -553,7 +555,6 @@ class tp5o_scroll(PageloaderTest):
     tppagecycles = 12
     gecko_profile_interval = 2
     gecko_profile_entries = 2000000
-
     tpscrolltest = True
     """ASAP mode"""
     tpmozafterpaint = False