xref: /external/perfetto/src/trace_processor/metrics/sql/chrome/scroll_jank_cause_queuing_delay.sql

--
-- Copyright 2020 The Android Open Source Project
--
-- Licensed under the Apache License, Version 2.0 (the 'License');
-- you may not use this file except in compliance with the License.
-- You may obtain a copy of the License at
--
--     https://www.apache.org/licenses/LICENSE-2.0
--
-- Unless required by applicable law or agreed to in writing, software
-- distributed under the License is distributed on an 'AS IS' BASIS,
-- WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-- See the License for the specific language governing permissions and
-- limitations under the License.

SELECT RUN_METRIC('chrome/chrome_thread_slice.sql');
SELECT RUN_METRIC('chrome/scroll_flow_event_queuing_delay.sql');

-- See b/184134310 why we remove ThreadController active.
DROP VIEW IF EXISTS blocking_tasks_no_threadcontroller_active;
CREATE VIEW blocking_tasks_no_threadcontroller_active AS
 SELECT
    slice.*,
    ancestor.id AS task_ancestor_id,
    ancestor.name AS task_ancestor_name
  FROM
    chrome_thread_slice AS slice LEFT JOIN
    ancestor_slice(slice.id) as ancestor ON ancestor.id = slice.parent_id
  WHERE
    slice.name != "ThreadController active" AND
    (slice.depth = 0 OR ancestor.name = "ThreadController active");

-- Sort track ids to optimize joining with slices
-- as engine doesn't do the sort to join in O(LogN)
-- per row by default
DROP VIEW IF EXISTS chrome_annotated_threads_and_processes;
CREATE VIEW chrome_annotated_threads_and_processes AS
  SELECT
    thread_track.id AS track_id,
    chrome_thread.canonical_name AS thread_name,
    chrome_process.process_type AS process_name
  FROM
    thread_track JOIN
    chrome_thread JOIN
    chrome_process ON
    thread_track.utid = chrome_thread.utid AND
    chrome_thread.upid = chrome_process.upid
  ORDER BY
    track_id ASC;

-- See b/166441398 & crbug/1094361 for why we remove threadpool (originally
-- the -to-End step). In essence -to-End is often reported on the ThreadPool
-- after the fact with explicit timestamps so it being blocked isn't noteworthy.
DROP VIEW IF EXISTS blocking_chrome_tasks_without_threadpool;
CREATE VIEW blocking_chrome_tasks_without_threadpool AS
  SELECT
     slice.*,
     annotations.thread_name AS thread_name,
     annotations.process_name AS process_name
  FROM
    blocking_tasks_no_threadcontroller_active AS slice JOIN
    chrome_annotated_threads_and_processes AS annotations ON
    annotations.track_id = slice.track_id
  WHERE
    NOT (thread_name GLOB "*ThreadPool*");

-- This view grabs any slice that could have prevented any GestureScrollUpdate
-- flow event from being run (queuing delays). For RunTask we know that its
-- generic (and thus hard to figure out whats the cause) so we grab the src
-- location to make it more meaningful.
--
-- See b/184134310 for why we allow depth == 1 and ancestor.id is null (which
-- implies its a "ThreadController active" slice because we removed it
-- previously).
DROP TABLE IF EXISTS blocking_tasks_queuing_delay;
CREATE TABLE blocking_tasks_queuing_delay AS
  SELECT
    EXTRACT_ARG(slice.arg_set_id, "task.posted_from.file_name") as file,
    EXTRACT_ARG(slice.arg_set_id, "task.posted_from.function_name") as function,
    trace_id,
    queuing_time_ns,
    avg_vsync_interval,
    next_track_id,
    CASE WHEN queuing.ancestor_end <= slice.ts THEN
      CASE WHEN slice.ts + slice.dur <= queuing.maybe_next_ancestor_ts THEN
        slice.dur
      ELSE
        queuing.maybe_next_ancestor_ts - slice.ts
      END
    ELSE
      CASE WHEN slice.ts + slice.dur <= queuing.maybe_next_ancestor_ts THEN
        slice.ts + slice.dur - queuing.ancestor_end
      ELSE
        queuing.maybe_next_ancestor_ts - queuing.ancestor_end
      END
    END AS dur_overlapping_ns,
    description,
    scroll_slice_id,
    scroll_ts,
    scroll_dur,
    scroll_track_id,
    jank,
    slice.*
  FROM
    scroll_flow_event_queuing_delay queuing JOIN
    blocking_chrome_tasks_without_threadpool AS slice ON
        slice.ts + slice.dur > queuing.ancestor_end AND
        queuing.maybe_next_ancestor_ts > slice.ts AND
        slice.track_id = queuing.next_track_id
  WHERE
    queuing_time_ns IS NOT NULL AND
    queuing_time_ns > 0;

-- Now for each toplevel task (depth = 0 from above) we want to grab all their
-- children slices. This is done by joining on descendant_slice which is a
-- trace processor defined operator. This will results in 1 row for every
-- descendant slice. So all fields in base.* will be repeated ONCE for each
-- child, but if it has no slice it will occur only once but all the
-- |descendant_.*| fields will be NULL because of the LEFT JOIN.
-- Additionally for mojo events we replace the descendant_name with just the
-- "interface_name" since that is more descriptive for our jank purposes.
DROP VIEW IF EXISTS all_descendant_blocking_tasks_queuing_delay;
CREATE VIEW all_descendant_blocking_tasks_queuing_delay AS
  SELECT
    descendant.id AS descendant_id,
    descendant.ts AS descendant_ts,
    descendant.dur AS descendant_dur,
    COALESCE(
      IIF(descendant.arg_set_id IS NOT NULL,
          EXTRACT_ARG(descendant.arg_set_id,
              "chrome_mojo_event_info.watcher_notify_interface_tag"),
          NULL),
      IIF(descendant.arg_set_id IS NOT NULL,
          EXTRACT_ARG(descendant.arg_set_id,
              "chrome_mojo_event_info.mojo_interface_tag"),
          NULL),
      descendant.name) AS descendant_name,
    EXTRACT_ARG(descendant.arg_set_id,
        "chrome_mojo_event_info.ipc_hash") AS descendant_ipc_hash,
    descendant.parent_id As descendant_parent_id,
    descendant.depth AS descendant_depth,
    descendant.category AS descendant_category,
    base.*
  FROM
    blocking_tasks_queuing_delay base LEFT JOIN
    descendant_slice(base.id) AS descendant;

DROP TABLE IF EXISTS all_descendant_blocking_tasks_queuing_delay_with_cpu_time;
CREATE TABLE all_descendant_blocking_tasks_queuing_delay_with_cpu_time AS
  SELECT
    cpu.thread_dur AS descendant_thread_dur,
    CAST(cpu.thread_dur AS REAL) / descendant.thread_dur
        AS descendant_cpu_percentage,
    CAST(cpu.thread_dur AS REAL) /
        (descendant.thread_dur /
          (1 << (descendant.descendant_depth - 1))) > 0.5
            AS descendant_cpu_time_above_relative_threshold,
    descendant_dur / descendant.dur AS descendant_dur_percentage,
    descendant_dur /
        (descendant.dur / (1 << (descendant.descendant_depth - 1))) > 0.5
        AS descendant_dur_above_relative_threshold,
    descendant.*
  FROM
    all_descendant_blocking_tasks_queuing_delay descendant LEFT JOIN (
      SELECT
        id, thread_dur
      FROM chrome_thread_slice
    ) AS cpu ON
        cpu.id = descendant.descendant_id;

-- Now that we've generated the descendant count how many siblings each row
-- has. Recall that all the top level tasks are repeated but each row represents
-- a descendant slice. This means since we LEFT JOIN we will say a slice has 0
-- siblings if it has no descendants (which is true), and otherwise we will
-- compute the siblings as the count of all slices with the same parent minus
-- the current slice.
DROP VIEW IF EXISTS counted_descendant_blocking_tasks_queuing_delay;
CREATE VIEW counted_descendant_blocking_tasks_queuing_delay AS
  SELECT
    base.*,
    COALESCE(single_descendant.number_of_siblings, 0) AS number_of_siblings
  FROM
    all_descendant_blocking_tasks_queuing_delay_with_cpu_time base LEFT JOIN (
      SELECT
        descendant_parent_id,
        COUNT(*) - 1 AS number_of_siblings
      FROM all_descendant_blocking_tasks_queuing_delay_with_cpu_time
      WHERE descendant_parent_id IS NOT NULL
      GROUP BY 1
  ) single_descendant ON
      single_descendant.descendant_parent_id = base.descendant_parent_id;

-- Now we group by the |id| which is the top level task id and find the first
-- descendant_depth where we have a sibling. We need this because we only want
-- to include single descendant slices in our metric name to keep it easy to
-- reason about what that code is doing.
DROP VIEW IF EXISTS blocking_tasks_queuing_delay_with_invalid_depth;
CREATE VIEW blocking_tasks_queuing_delay_with_invalid_depth AS
  SELECT
    base.*,
    (
      descendant_cpu_time_above_relative_threshold AND
      descendant_cpu_percentage > 0.05
    ) OR (
      descendant_dur_above_relative_threshold AND
      descendant_dur_percentage > 0.05
    ) AS descendant_major_slice,
    COALESCE(depth.invalid_depth, 10) AS invalid_depth
  FROM
    counted_descendant_blocking_tasks_queuing_delay base LEFT JOIN (
      SELECT
        id,
        MIN(descendant_depth) AS invalid_depth
      FROM counted_descendant_blocking_tasks_queuing_delay
      WHERE number_of_siblings >= 1
      GROUP BY 1
    ) AS depth ON base.id = depth.id
  ORDER BY
    descendant_depth ASC,
    descendant_cpu_percentage DESC,
    descendant_dur_percentage DESC;

-- Now to get back to a single output per top level task we group by all the
-- toplevel fields and aggregate the descendant fields. We only include the
-- descendant if their depth is less than the first depth with siblings (the
-- |invalid_depth|).
DROP VIEW IF EXISTS descendant_blocking_tasks_queuing_delay;
CREATE VIEW descendant_blocking_tasks_queuing_delay AS
  SELECT
    id,
    ts,
    dur,
    track_id,
    trace_id,
    name,
    category,
    scroll_slice_id AS scroll_id,
    scroll_ts,
    scroll_dur,
    scroll_track_id,
    jank,
    queuing_time_ns,
    dur_overlapping_ns,
    description,
    replace(file, rtrim(file, replace(file, '/', '')), '') AS file,
    thread_name,
    process_name,
    function,
    avg_vsync_interval,
    GROUP_CONCAT(
      CASE WHEN descendant_depth < invalid_depth OR descendant_major_slice THEN
        descendant_id
      ELSE
        NULL
      END
    , "-") AS descendant_id,
    GROUP_CONCAT(
      CASE WHEN descendant_depth < invalid_depth OR descendant_major_slice THEN
        descendant_ts
      ELSE
        NULL
      END
    , "-") AS descendant_ts,
    GROUP_CONCAT(
      CASE WHEN descendant_depth < invalid_depth OR descendant_major_slice THEN
        descendant_dur
      ELSE
        NULL
      END
    , "-") AS descendant_dur,
    GROUP_CONCAT(
      CASE WHEN descendant_depth < invalid_depth OR descendant_major_slice THEN
        descendant_name
      ELSE
        NULL
      END, "-") AS descendant_name,
    GROUP_CONCAT(
      CASE WHEN descendant_depth < invalid_depth OR descendant_major_slice THEN
        descendant_thread_dur
      ELSE
        NULL
      END
    , "-") AS descendant_thread_dur,
    GROUP_CONCAT(
      CASE WHEN descendant_depth < invalid_depth OR descendant_major_slice THEN
        descendant_cpu_percentage
      ELSE
        NULL
      END
    , "-") AS descendant_cpu_time,
    GROUP_CONCAT(
      CASE WHEN descendant_category = "mojom" THEN
        descendant_name
      ELSE
        NULL
      END
    , "-") AS mojom_name,
    -- All ipc_hashes should be equal so just select the first non-null one.
    MIN(descendant_ipc_hash) AS mojom_ipc_hash,
    GROUP_CONCAT(
      CASE WHEN
        descendant_category = "toplevel" AND
        descendant_name NOT GLOB "*ThreadController*" THEN
          descendant_name
      ELSE
          NULL
      END
    , "-") AS toplevel_name,
    GROUP_CONCAT(
      CASE WHEN descendant_category = "Java" THEN
        descendant_name
      ELSE
        NULL
      END
    , "-") AS java_name
  FROM
    blocking_tasks_queuing_delay_with_invalid_depth
  GROUP BY 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20
  ORDER BY descendant_cpu_percentage DESC;

SELECT CREATE_FUNCTION(
  -- Function prototype: takes a '-' separated list of slice names (formed by
  -- the GROUP_CONCAT above) and returns the first slice if any or NULL
  -- otherwise.
  'GetFirstSliceNameOrNull(name STRING)',
  -- Returns the first slice name or NULL
  'STRING',
  -- Preforms the actual string modification, takes the either the whole string
  -- if there is no '-' or up to the first '-'. SUBSTR returns NULL if $name is
  -- NULL.
  'SELECT SUBSTR($name, 0,
    CASE WHEN INSTR($name, "-") = 0 THEN
      LENGTH($name)+1 ELSE
      INSTR($name, "-")
    END)'
);

SELECT CREATE_FUNCTION(
  -- Function prototype: takes a '-' separated list of slice names (formed by
  -- the GROUP_CONCAT above) and checks for certain important view names and
  -- falls back on GetFirstSliceNameOrNull if it can't find one.
  'GetJavaSliceSummaryOrNull(name STRING)',
  -- Returns the summary of the provided list of java slice names.
  'STRING',
  -- Performs a bunch of GLOB matches in an order, now there could be multiple
  -- matches (both Toolbar & TabList could be true) so the order matters in
  -- tagging since we don't support multiple tagging of values. Ideally we would
  -- determine which one was the longest duration, but this should be sufficient
  -- for now.
  'SELECT
    CASE WHEN $name GLOB "*ToolbarControlContainer*" THEN
      "ToolbarControlContainer"
    WHEN $name GLOB "*ToolbarProgressBar*" THEN
      "ToolbarProgressBar"
    WHEN $name GLOB "*TabGroupUiToolbarView*" THEN
      "TabGroupUiToolbarView"
    WHEN $name GLOB "*TabGridThumbnailView*" THEN
      "TabGridThumbnailView"
    WHEN $name GLOB "*TabGridDialogView*" THEN
      "TabGridDialogView"
    WHEN $name GLOB "*BottomContainer*" THEN
      "BottomContainer"
    WHEN $name GLOB "*FeedSwipeRefreshLayout*" THEN
      "FeedSwipeRefreshLayout"
    WHEN $name GLOB "*AutocompleteEditText*" THEN
      "AutocompleteEditText"
    WHEN $name GLOB "*HomeButton*" THEN
      "HomeButton"
    WHEN $name GLOB "*ToggleTabStackButton*" THEN
      "ToggleTabStackButton"
    WHEN $name GLOB "*ListMenuButton*" THEN
      "ListMenuButton"
    WHEN $name GLOB "*ScrimView*" THEN
      "ScrimView"
    WHEN $name GLOB "*ChromeImageView*" THEN
      "ChromeImageView"
    WHEN $name GLOB "*AppCompatImageView*" THEN
      "AppCompatImageView"
    WHEN $name GLOB "*ChromeImageButton*" THEN
      "ChromeImageButton"
    WHEN $name GLOB "*AppCompatImageButton*" THEN
      "AppCompatImageButton"
    WHEN $name GLOB "*TabListRecyclerView*" THEN
      "TabListRecyclerView"
    ELSE
      GetFirstSliceNameOrNull($name)
    END'
);

SELECT CREATE_FUNCTION(
  -- Function prototype: takes slice name, category and descendant_name and
  -- determines if this event should be classified as unknown or not.
  'UnknownEventOrEmptyString(name STRING, cat STRING, has_descendant STRING)',
  -- Returns either "-UnknownEvent" or "".
  'STRING',
  -- If our current event has a posted from we consider it already categorized
  -- even if we don't have events underneath it. If its java often we won't have
  -- sub events, and finally if its a single event we just use its name there
  -- isn't anything under to use so just leave it at that.
  'SELECT
    CASE WHEN
      $name = "ThreadControllerImpl::RunTask" OR
      $cat = "Java" OR
      $has_descendant IS NULL THEN
        "" ELSE
        "-UnknownEvent"
      END'
);

SELECT CREATE_FUNCTION(
  -- Function prototype: Takes a slice name, function, and file, and determines
  -- if we should use the slice name, or if its a RunTask event uses the
  -- function & file name, however if the RunTask posted from is one of the
  -- simple_watcher paths we collapse them for attributation.
  'TopLevelName(name STRING, function STRING, file STRING)',
  'STRING',
  -- The difference for the mojom functions are:
  --  1) PostDispatchNextMessageFromPipe:
  --         We knew that there is a message in the pipe, didn't try to set up a
  --         SimpleWatcher to monitor when a new one arrives.
  --  2) ArmOrNotify:
  --         We tried to set up SimpleWatcher, but the setup failed as the
  --         message arrived as we were setting this up, so we posted a task
  --         instead.
  --  3) Notify:
  --         SimpleWatcher was set up and after a period of monitoring detected
  --         a new message.
  -- For our jank use case this distinction isn't very useful so we group them
  -- together.
  'SELECT
     CASE WHEN $name = "ThreadControllerImpl::RunTask" THEN
       CASE WHEN $function IN
           ("PostDispatchNextMessageFromPipe", "ArmOrNotify", "Notify") THEN
         "posted-from-mojo-pipe"
        ELSE
         "posted-from-" || $function || "()-in-" || $file
        END
    ELSE
      $name
    END'
);

-- Create a common name for each "cause" based on the slice stack we found.
DROP VIEW IF EXISTS scroll_jank_cause_queuing_delay_temp;
CREATE VIEW scroll_jank_cause_queuing_delay_temp AS
  SELECT
    TopLevelName(name, function, file) || COALESCE(
      "-" || descendant_name, "") AS location,
    TopLevelName(name, function, file) || COALESCE(
      "-" || GetFirstSliceNameOrNull(mojom_name)
          || COALESCE("(ipc=" || mojom_ipc_hash || ")", ""),
      "-" || GetFirstSliceNameOrNull(toplevel_name)
          || COALESCE("(ipc=" || mojom_ipc_hash || ")", ""),
      "-" || GetJavaSliceSummaryOrNull(java_name),
      UnknownEventOrEmptyString(name, category, descendant_name)
    ) AS restricted_location,
    base.*
  FROM descendant_blocking_tasks_queuing_delay base;

-- Figure out the average time taken during non-janky scrolls updates for each
-- TraceEvent (metric_name) stack.
DROP VIEW IF EXISTS scroll_jank_cause_queuing_delay_average_no_jank_time;
CREATE VIEW scroll_jank_cause_queuing_delay_average_no_jank_time AS
  SELECT
    location,
    AVG(dur_overlapping_ns) as avg_dur_overlapping_ns
  FROM scroll_jank_cause_queuing_delay_temp
  WHERE NOT jank
  GROUP BY 1;

-- Again figure out the average time, but based on a more restricted set of
-- trace events.
DROP VIEW IF EXISTS scroll_jank_cause_queuing_delay_average_no_jank_time_restricted;
CREATE VIEW scroll_jank_cause_queuing_delay_average_no_jank_time_restricted AS
  SELECT
    restricted_location,
    AVG(dur_overlapping_ns) as avg_dur_overlapping_ns_restricted
  FROM scroll_jank_cause_queuing_delay_temp
  WHERE NOT jank
  GROUP BY 1;


-- Join every row (jank and non-jank with the average non-jank time for the
-- given metric_name).
DROP VIEW IF EXISTS scroll_jank_cause_queuing_delay_unannotated;
CREATE VIEW scroll_jank_cause_queuing_delay_unannotated AS
  SELECT
    base.*,
    'InputLatency.LatencyInfo.Flow.QueuingDelay.' ||
    CASE WHEN jank THEN 'Jank' ELSE 'NoJank' END || '.BlockingTasksUs.' ||
      base.location as metric_name,
    COALESCE(avg_no_jank.avg_dur_overlapping_ns, 0)
        AS avg_no_jank_dur_overlapping_ns
  FROM
    scroll_jank_cause_queuing_delay_temp base LEFT JOIN
    scroll_jank_cause_queuing_delay_average_no_jank_time avg_no_jank ON
        base.location = avg_no_jank.location;

-- Join in the restricted set of trace events average as well to form the final output.
DROP VIEW IF EXISTS scroll_jank_cause_queuing_delay;
CREATE VIEW scroll_jank_cause_queuing_delay AS
  SELECT
    base.*,
    'QueuingDelay.' ||
    CASE WHEN jank THEN 'Jank' ELSE 'NoJank' END || '.BlockingTasksUs.' ||
      base.restricted_location AS restricted_metric_name,
    COALESCE(avg_no_jank.avg_dur_overlapping_ns_restricted, 0)
        AS avg_no_jank_dur_overlapping_ns_restricted
  FROM
    scroll_jank_cause_queuing_delay_unannotated base LEFT JOIN
    scroll_jank_cause_queuing_delay_average_no_jank_time_restricted avg_no_jank ON
        base.restricted_location = avg_no_jank.restricted_location;