Support tracing metrics for measureTime & measureFrameTime method in blink_perf

third_party/WebKit/PerformanceTests/resources/runner.js

 // There are tests for computeStatistics() located in LayoutTests/fast/harness/perftests
 
 if (window.testRunner) {
     testRunner.waitUntilDone();
     testRunner.dumpAsText();
 }
 
 (function () {
     var logLines = null;
     var completedIterations = -1;
@@ skipping 139 matching lines @@
             return;
         }
         currentTest = test;
         iterationCount = test.iterationCount || (window.testRunner ? 5 : 20);
         if (test.warmUpCount && test.warmUpCount > 0)
             completedIterations = -test.warmUpCount;
         logLines = PerfTestRunner.bufferedLog || window.testRunner ? [] : null;
         PerfTestRunner.log("Running " + iterationCount + " times");
         if (test.doNotIgnoreInitialRun)
             completedIterations++;
-        if (runner)
+
+        if (runner && test.tracingCategories && window.testRunner &&
+            window.testRunner.supportTracing) {
+            window.testRunner.traceEventsToMeasure = test.traceEventsToMeasure;
+            window.testRunner.startTracing(test.tracingCategories, function() {
+                scheduleNextRun(scheduler, runner);
+            });
+        } else if (runner) {
             scheduleNextRun(scheduler, runner);
+        }
     }
 
     function scheduleNextRun(scheduler, runner) {
         scheduler(function () {
             // This will be used by tools/perf/benchmarks/blink_perf.py to find
             // traces during the measured runs.
             if (completedIterations >= 0)
                 console.time("blink_perf");
 
             try {
@@ skipping 46 matching lines @@
             }
             if (logLines)
                 logLines.forEach(logInDocument);
             window.scrollTo(0, document.body.offsetHeight);
             if (currentTest.done)
                 currentTest.done();
         } catch (exception) {
             logInDocument("Got an exception while finalizing the test with name=" + exception.name + ", message=" + exception.message);
         }
 
-        if (window.testRunner)
-            testRunner.notifyDone();
+        if (window.testRunner) {
+            if (currentTest.traceEventsToMeasure &&
+                testRunner.supportTracing) {
+                testRunner.stopTracingAndMeasure(
+                    currentTest.traceEventsToMeasure, function() {

[nednguyen, 2017/04/24 22:37:34]

not sure why but here, I can't just put
"testRunner.stopTracingAndMeasure(currentTest.traceEventsToMeasure,
testRunner.notifyDone)". If someone who is more familiar with JS can enlighten
me on this, I would really appreciate it.  :P

[Xianzhu, 2017/04/24 22:46:04]

topTracingAndMeasure(..., testRunner.notifyDone) doesn't work because callback
will be called as a function without an object so notifyDone() will have no
'this' object.

+                        testRunner.notifyDone();
+                    });
+            } else {
+                testRunner.notifyDone();
+            }
+        }
     }
 
     PerfTestRunner.prepareToMeasureValuesAsync = function (test) {
         PerfTestRunner.unit = test.unit;
         start(test);
     }
 
     PerfTestRunner.measureValueAsync = function (measuredValue) {
         completedIterations++;
 
         try {
             ignoreWarmUpAndLog(measuredValue);
         } catch (exception) {
             PerfTestRunner.logFatalError("Got an exception while logging the result with name=" + exception.name + ", message=" + exception.message);
             return;
         }
 
         if (completedIterations >= iterationCount)
             finish();
     }
 
+    function addRunTestStartMarker() {
+      if (!window.testRunner || !window.testRunner.supportTracing)
+          return;
+      if (completedIterations < 0)
+          console.time('blink_perf.runTest.warmup');
+      else
+          console.time('blink_perf.runTest');
+    }
+
+    function addRunTestEndMarker() {
+      if (!window.testRunner || !window.testRunner.supportTracing)
+          return;
+      if (completedIterations < 0)
+          console.timeEnd('blink_perf.runTest.warmup');
+      else
+          console.timeEnd('blink_perf.runTest');
+    }
+
+
     PerfTestRunner.measureFrameTime = function (test) {
         PerfTestRunner.unit = "ms";
         PerfTestRunner.bufferedLog = true;
         test.warmUpCount = test.warmUpCount || 5;
         test.iterationCount = test.iterationCount || 10;
         // Force gc before starting the test to avoid the measured time from
         // being affected by gc performance. See crbug.com/667811#c16.
         PerfTestRunner.gc();
         start(test, requestAnimationFrame, measureFrameTimeOnce);
     }
 
     var lastFrameTime = -1;
     function measureFrameTimeOnce() {
+        if (lastFrameTime != -1)
+          addRunTestEndMarker();
         var now = PerfTestRunner.now();
         var result = lastFrameTime == -1 ? -1 : now - lastFrameTime;
         lastFrameTime = now;
+        addRunTestStartMarker();
 
         var returnValue = currentTest.run();
         if (returnValue - 0 === returnValue) {
             if (returnValue < 0)
                 PerfTestRunner.log("runFunction returned a negative value: " + returnValue);
             return returnValue;
         }
 
         return result;
     }
 
     PerfTestRunner.measureTime = function (test) {
         PerfTestRunner.unit = "ms";
         PerfTestRunner.bufferedLog = true;
         start(test, zeroTimeoutScheduler, measureTimeOnce);
     }
 
     function zeroTimeoutScheduler(task) {
         setTimeout(task, 0);
     }
 
     function measureTimeOnce() {
         // Force gc before measuring time to avoid interference between tests.
         PerfTestRunner.gc();
 
         var start = PerfTestRunner.now();
+        addRunTestStartMarker();
         var returnValue = currentTest.run();
+        addRunTestEndMarker();
         var end = PerfTestRunner.now();
 
         if (returnValue - 0 === returnValue) {
             if (returnValue < 0)
                 PerfTestRunner.log("runFunction returned a negative value: " + returnValue);
             return returnValue;
         }
 
         return end - start;
     }
@@ skipping 63 matching lines @@
 
             iframe.contentDocument.close();
             document.body.removeChild(iframe);
         };
 
         PerfTestRunner.measureTime(test);
     }
 
     window.PerfTestRunner = PerfTestRunner;
 })();