[LoadLine] Output loading stage breakdown

Refine the breakdown query for the LoadLine benchmark:
* Drop the "init" stage since it's not useful
* Track both "network" and "process_launch" from the navigation start
* Make the query work for non-debug loadline (remove dependency on
  extra categories)

Also add the query to the non-debug config and print the breakdown
along with the benchmark scores.

Change-Id: Ifb4c15d439bcd5a07730206e641655bd07cfd6b3
Reviewed-on: https://chromium-review.googlesource.com/c/crossbench/+/6633000
Commit-Queue: Mikhail Khokhlov <[email protected]>
Reviewed-by: Victor Vianna <[email protected]>

Author: khokhlov962

config/benchmark/loadline/probe_config.hjson

@@ -5,6 +5,7 @@
     trace_processor: {
       queries: [
         "loadline/benchmark_score",
+        "loadline/breakdown",
       ],
       batch: false,
     },

config/benchmark/loadline/probe_config_experimental.hjson

@@ -3,6 +3,7 @@
     trace_processor: {
       queries: [
         "loadline/benchmark_score",
+        "loadline/breakdown",
         "loadline/experimental/cpu",
         "loadline/experimental/dom",
         "loadline/experimental/interaction_latency",

crossbench/benchmarks/loadline/loadline.py

@@ -33,30 +33,46 @@ class LoadLineProbe(BenchmarkProbeMixin, Probe):
   BENCHMARK_NAME: str = "LoadLine"
   BENCHMARK_VERSION: str = ""
 
+  def __init__(self, *args, **kwargs):
+    super().__init__(*args, **kwargs)
+    self._scores_file: Optional[pth.LocalPath] = None
+    self._breakdown_file: Optional[pth.LocalPath] = None
+
   @override
   def log_browsers_result(self, group: BrowsersRunGroup) -> None:
-    logging.info("-" * 80)
     logging.critical("%s Benchmark (%s)", self.BENCHMARK_NAME,
                      self.BENCHMARK_VERSION)
-    logging.critical("%s results:", self.BENCHMARK_NAME)
+    logging.info("-" * 80)
+    logging.critical("%s scores:", self.BENCHMARK_NAME)
+    logging.critical(
+        tabulate(
+            pd.read_csv(self._scores_file), headers="keys", tablefmt="plain"))
     logging.info("- " * 40)
+    logging.critical("%s breakdown (loading stage durations, in ms):",
+                     self.BENCHMARK_NAME)
     logging.critical(
         tabulate(
-            pd.read_csv(
-                group.get_local_probe_result_path(self).with_suffix(".csv")),
-            headers="keys",
+            pd.read_csv(self._breakdown_file), headers="keys",
             tablefmt="plain"))
 
   @override
   def merge_browsers(self, group: BrowsersRunGroup) -> ProbeResult:
-    csv_file = group.get_local_probe_result_path(self).with_suffix(".csv")
-    self._compute_score(group).to_csv(csv_file)
-    return LocalProbeResult(csv=(csv_file,))
+    self._scores_file = group.get_local_probe_result_path(self).with_name(
+        "benchmark_score.csv")
+    self._compute_score(group).to_csv(self._scores_file)
+    self._breakdown_file = group.get_local_probe_result_path(self).with_name(
+        "breakdown.csv")
+    self._compute_breakdown(group).to_csv(self._breakdown_file)
+    return LocalProbeResult(csv=(self._scores_file, self._breakdown_file))
 
   @abc.abstractmethod
   def _compute_score(self, group: BrowsersRunGroup) -> pd.DataFrame:
     pass
 
+  @abc.abstractmethod
+  def _compute_breakdown(self, group: BrowsersRunGroup) -> pd.DataFrame:
+    pass
+
 
 class LoadLinePageFilter(LoadingPageFilter):
   """LoadLine benchmark for phone/tablet."""

crossbench/benchmarks/loadline/loadline_1.py

@@ -6,6 +6,7 @@
 
 from typing import TYPE_CHECKING, Type
 
+import logging
 import numpy as np
 import pandas as pd
 from typing_extensions import override
@@ -29,6 +30,30 @@
 VERSION_STRING = "1.3.0"
 
 
+def process_scores(df: pd.DataFrame) -> pd.DataFrame:
+  df = df.groupby(["cb_browser",
+                   "cb_story"])["score"].mean().reset_index().pivot(
+                       columns=["cb_story"],
+                       index=["cb_browser"],
+                       values=["score"])
+  df = df.droplevel(0, axis=1)
+  df["TOTAL_SCORE"] = np.exp(np.log(df).mean(axis=1))
+  df.index.rename("browser", inplace=True)
+  df = df.reindex(
+      columns=(["TOTAL_SCORE"] +
+               sorted(list(c for c in df.columns if c != "TOTAL_SCORE"))))
+  return df
+
+
+def process_breakdown(df: pd.DataFrame) -> pd.DataFrame:
+  df["os"] = df[["network", "process_launch"]].max(axis=1)
+  df = df.groupby(["cb_browser", "cb_story"
+                  ])[["os", "renderer", "compositor", "gpu",
+                      "surfaceflinger"]].mean()
+  df.index.names = ["browser", "story"]
+  return df
+
+
 class LoadLine1Probe(LoadLineProbe):
   NAME = "loadline_probe"
   BENCHMARK_NAME = "LoadLine"
@@ -38,29 +63,30 @@ class LoadLine1Probe(LoadLineProbe):
   def get_context_cls(self,) -> Type[LoadLine1ProbeContext]:
     return LoadLine1ProbeContext
 
-  @override
-  def _compute_score(self, group: BrowsersRunGroup) -> pd.DataFrame:
+  def _load_query_result(self, group: BrowsersRunGroup,
+                         query: str) -> pd.DataFrame:
     all_results = group.results.get_by_name(TraceProcessorProbe.NAME).csv_list
-    loadline_result: pth.LocalPath | None = None
+    query_result: pth.LocalPath | None = None
     for result in all_results:
-      # Look for the trace processor query result.
-      if result.name == "loadline_benchmark_score.csv":
-        loadline_result = result
+      if result.stem == query:
+        query_result = result
         break
-    assert loadline_result is not None, f"{self.NAME}: query result not found"
-
-    df = pd.read_csv(loadline_result)
-    df = df.groupby(["cb_browser",
-                     "cb_story"])["score"].mean().reset_index().pivot(
-                         columns=["cb_story"],
-                         index=["cb_browser"],
-                         values=["score"])
-    df = df.droplevel(0, axis=1)
-    df["TOTAL_SCORE"] = np.exp(np.log(df).mean(axis=1))
-    df.index.rename("browser", inplace=True)
-    return df.reindex(
-        columns=(["TOTAL_SCORE"] +
-                 sorted(list(c for c in df.columns if c != "TOTAL_SCORE"))))
+    assert query_result is not None, f"{self.NAME}: {query} result not found"
+    return pd.read_csv(query_result)
+
+  @override
+  def _compute_score(self, group: BrowsersRunGroup) -> pd.DataFrame:
+    df = self._load_query_result(group, "loadline_benchmark_score")
+    return process_scores(df)
+
+  @override
+  def _compute_breakdown(self, group: BrowsersRunGroup) -> pd.DataFrame:
+    df = self._load_query_result(group, "loadline_breakdown")
+    if any(df["network"] > df["process_launch"]):
+      logging.warning("Some runs were affected by network latency. "
+                      "Results can be non-representative.")
+    return process_breakdown(df)
+
 
 
 class LoadLine1ProbeContext(ProbeContext[LoadLine1Probe]):

crossbench/benchmarks/loadline/loadline_2.py

@@ -57,6 +57,11 @@ def _compute_score(self, group: BrowsersRunGroup) -> pd.DataFrame:
         columns=(["TOTAL_SCORE"] +
                  sorted(list(c for c in total.columns if c != "TOTAL_SCORE"))))
 
+  @override
+  def _compute_breakdown(self, group: BrowsersRunGroup) -> pd.DataFrame:
+    # TODO(crbug.com/425325733): Implement breakdown for LoadLine 2.
+    return pd.DataFrame(index=pd.Index([], name="Not implemented"))
+
 
 class LoadLine2ProbeContext(ProbeContext[LoadLine2Probe]):
 

crossbench/probes/perfetto/trace_processor/modules/ext/loadline_stages.sql

@@ -1,29 +1,31 @@
+-- Create tables with page loading breakdown into stages for the LoadLine
+-- benchmark.
+-- TODO(crbug.com/425325733): Support LoadLine 2 as well.
+
 INCLUDE PERFETTO MODULE ext.loadline_benchmark;
 
 DROP VIEW IF EXISTS loadline_presentation;
 CREATE VIEW loadline_presentation AS
 SELECT
   first_navigation_start() + 60e9 / loadline_benchmark_score() AS presentation;
 
+-- Finds the "Commit sent" moment which is the time when the browser gets the
+-- response from the network stack.
 DROP VIEW IF EXISTS loadline_request;
 CREATE VIEW loadline_request AS
-SELECT ts AS start_request, ts + dur AS end_request
+SELECT MIN(ts) AS end_request
 FROM slice
 WHERE
-  name = 'WillStartRequest'
-  AND ts >= first_navigation_start()
-ORDER BY ts
-LIMIT 1;
+  name = 'CommitSentToFirstSubresourceLoadStart'
+  AND ts >= first_navigation_start();
 
 DROP VIEW IF EXISTS loadline_renderer_ready;
 CREATE VIEW loadline_renderer_ready AS
-SELECT ts + dur AS renderer_ready
+SELECT MIN(ts) AS renderer_ready
 FROM slice
 WHERE
-  name = 'ReadyToCommitNavigation'
-  AND ts >= first_navigation_start()
-ORDER BY ts
-LIMIT 1;
+  name = 'DocumentLoader::CommitNavigation'
+  AND ts >= first_navigation_start();
 
 -- Find the frame in the pipeline which was chosen as the "loading complete"
 -- moment for the purpose of LoadLine score. The exact end timestamp might
@@ -69,7 +71,6 @@ DROP VIEW IF EXISTS loadline_stages;
 CREATE VIEW loadline_stages AS
 SELECT
   first_navigation_start() AS navigation_start,
-  start_request,
   end_request,
   renderer_ready,
   frame_commit,

crossbench/probes/perfetto/trace_processor/queries/loadline/breakdown.sql

@@ -3,15 +3,16 @@ INCLUDE PERFETTO MODULE ext.loadline_stages;
 -- Reports durations of loadline stages in milliseconds.
 -- Stages approximately correspond to the Chrome subsystem which is most
 -- important for the page loading performance.
+-- Note that "network" and "process_launch" stages happen in parallel, so page
+-- load is only blocked on the longer of the two.
 -- For more info on page loading process in Chrome, see the following docs:
 -- https://chromium.googlesource.com/chromium/src/+/main/docs/navigation.md
 -- https://chromium.googlesource.com/chromium/src/+/main/docs/life_of_a_frame.md
 -- https://chromium.googlesource.com/chromium/src/+/main/components/page_load_metrics/
 SELECT
-  (start_request - navigation_start) / 1e6 AS init,
-  (end_request - start_request) / 1e6 AS network,
-  (renderer_ready - end_request) / 1e6 AS launch,
-  (frame_commit - renderer_ready) / 1e6 AS renderer,
+  (end_request - navigation_start) / 1e6 AS network,
+  (renderer_ready - navigation_start) / 1e6 AS process_launch,
+  (frame_commit - MAX(renderer_ready, end_request)) / 1e6 AS renderer,
   (submit_compositor_frame - frame_commit) / 1e6 AS compositor,
   (frame_swap - submit_compositor_frame) / 1e6 AS gpu,
   (presentation - frame_swap) / 1e6 AS surfaceflinger

tests/crossbench/benchmarks/test_loadline.py

@@ -11,17 +11,19 @@
 import datetime as dt
 from typing import Sequence
 
+import pandas as pd
 from typing_extensions import override
 
 from crossbench.action_runner.default_action_runner import DefaultActionRunner
 from crossbench.benchmarks.loadline import (LoadLine1PhoneBenchmark,
                                             LoadLine1TabletBenchmark)
+from crossbench.benchmarks.loadline import loadline_1
 from crossbench.benchmarks.loadline.loadline import LoadLinePageFilter
 from crossbench.benchmarks.loading.playback_controller import \
     PlaybackController
 from crossbench.benchmarks.loading.tab_controller import TabController
 from tests import test_helper
-from tests.crossbench.base import BaseCliTestCase
+from tests.crossbench.base import BaseCliTestCase, BaseCrossbenchTestCase
 from tests.crossbench.benchmarks.helper import SubStoryTestCase
 
 
@@ -100,8 +102,49 @@ def test_run_default_tablet(self):
     pass
 
 
+class TestLoadLine1Helpers(BaseCrossbenchTestCase):
+
+  def test_process_scores(self):
+    query_result = pd.DataFrame(
+        columns=["score", "cb_browser", "cb_story", "cb_temperature", "cb_run"],
+        data=[[4, "chrome", "story1", 0, 0], [6, "chrome", "story1", 0, 1],
+              [19, "chrome", "story2", 0, 0], [21, "chrome", "story2", 0, 1]])
+    scores = loadline_1.process_scores(query_result)
+
+    self.assertEqual(scores.shape, (1, 3))
+    self.assertAlmostEqual(scores["TOTAL_SCORE"][0], 10)
+    self.assertAlmostEqual(scores["story1"][0], 5)
+    self.assertAlmostEqual(scores["story2"][0], 20)
+
+  def test_process_breakdown(self):
+    query_result = pd.DataFrame(
+        columns=[
+            "network", "process_launch", "renderer", "compositor", "gpu",
+            "surfaceflinger", "cb_browser", "cb_story", "cb_temperature",
+            "cb_run"
+        ],
+        data=[[5, 3, 9, 11, 10, 10, "chrome", "story1", 0, 0],
+              [5, 3, 11, 9, 10, 10, "chrome", "story1", 0, 1],
+              [7, 10, 19, 21, 20, 20, "chrome", "story2", 0, 0],
+              [7, 10, 21, 19, 20, 20, "chrome", "story2", 0, 1]])
+    breakdown = loadline_1.process_breakdown(query_result)
+
+    self.assertEqual(breakdown.shape, (2, 5))
+    self.assertAlmostEqual(breakdown["os"][0], 5)
+    self.assertAlmostEqual(breakdown["os"][1], 10)
+    self.assertAlmostEqual(breakdown["renderer"][0], 10)
+    self.assertAlmostEqual(breakdown["renderer"][1], 20)
+    self.assertAlmostEqual(breakdown["compositor"][0], 10)
+    self.assertAlmostEqual(breakdown["compositor"][1], 20)
+    self.assertAlmostEqual(breakdown["gpu"][0], 10)
+    self.assertAlmostEqual(breakdown["gpu"][1], 20)
+    self.assertAlmostEqual(breakdown["surfaceflinger"][0], 10)
+    self.assertAlmostEqual(breakdown["surfaceflinger"][1], 20)
+
+
 # Don't expose abstract base test cases.
 del BaseLoadLineBenchmarkTestCase
+del BaseCrossbenchTestCase
 del BaseCliTestCase
 del SubStoryTestCase