• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1--
2-- Copyright 2020 The Android Open Source Project
3--
4-- Licensed under the Apache License, Version 2.0 (the "License");
5-- you may not use this file except in compliance with the License.
6-- You may obtain a copy of the License at
7--
8--     https://www.apache.org/licenses/LICENSE-2.0
9--
10-- Unless required by applicable law or agreed to in writing, software
11-- distributed under the License is distributed on an "AS IS" BASIS,
12-- WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13-- See the License for the specific language governing permissions and
14-- limitations under the License.
15
16SELECT RUN_METRIC('android/process_metadata.sql');
17
18DROP TABLE IF EXISTS android_sysui_cuj_last_cuj;
19CREATE TABLE android_sysui_cuj_last_cuj AS
20  SELECT
21    process.name AS name,
22    process.upid AS upid,
23    process_metadata.metadata AS process_metadata,
24    SUBSTR(slice.name, 3, LENGTH(slice.name) - 3) AS cuj_name,
25    ts AS ts_start,
26    ts + dur AS ts_end,
27    dur AS dur
28  FROM slice
29  JOIN process_track ON slice.track_id = process_track.id
30  JOIN process USING (upid)
31  JOIN process_metadata USING (upid)
32  WHERE
33    slice.name GLOB 'J<*>'
34    -- Filter out CUJs that are <4ms long - assuming CUJ was cancelled.
35    AND slice.dur > 4e6
36    AND (
37      process.name GLOB 'com.google.android*'
38      OR process.name GLOB 'com.android.*')
39  ORDER BY ts desc
40  LIMIT 1;
41
42SELECT RUN_METRIC(
43  'android/android_hwui_threads.sql',
44  'table_name_prefix', 'android_sysui_cuj',
45  'process_allowlist_table', 'android_sysui_cuj_last_cuj');
46
47DROP TABLE IF EXISTS android_sysui_cuj_do_frame_slices_in_cuj;
48CREATE TABLE android_sysui_cuj_do_frame_slices_in_cuj AS
49SELECT
50  slices.*,
51  lag(slices.ts_end) OVER (ORDER BY vsync ASC) as ts_prev_frame_end
52FROM android_sysui_cuj_do_frame_slices slices
53JOIN android_sysui_cuj_last_cuj last_cuj
54ON ts + slices.dur >= last_cuj.ts_start AND ts <= last_cuj.ts_end;
55
56DROP TABLE IF EXISTS android_sysui_cuj_vsync_boundaries;
57CREATE TABLE android_sysui_cuj_vsync_boundaries AS
58SELECT MIN(vsync) as vsync_min, MAX(vsync) as vsync_max
59FROM android_sysui_cuj_do_frame_slices_in_cuj;
60
61DROP TABLE IF EXISTS android_sysui_cuj_frame_expected_timeline_events;
62CREATE TABLE android_sysui_cuj_frame_expected_timeline_events AS
63  SELECT
64    CAST(e.name as INTEGER) as vsync,
65    e.ts as ts_expected,
66    e.dur as dur_expected,
67    MIN(a.ts) as ts_actual_min,
68    MAX(a.ts + a.dur) as ts_end_actual_max
69  FROM android_sysui_cuj_last_cuj cuj
70  JOIN expected_frame_timeline_slice e USING (upid)
71  JOIN android_sysui_cuj_vsync_boundaries vsync
72    ON CAST(e.name as INTEGER) >= vsync.vsync_min
73    AND CAST(e.name as INTEGER) <= vsync.vsync_max
74  JOIN actual_frame_timeline_slice a ON e.upid = a.upid AND e.name = a.name
75  GROUP BY e.name, e.ts, e.dur;
76
77DROP TABLE IF EXISTS android_sysui_cuj_frame_timeline_events;
78CREATE TABLE android_sysui_cuj_frame_timeline_events AS
79  SELECT
80    actual.layer_name as layer_name,
81    CAST(actual.name as INTEGER) as vsync,
82    actual.ts as ts_actual,
83    actual.dur as dur_actual,
84    actual.jank_type GLOB '*App Deadline Missed*' as app_missed,
85    actual.jank_type,
86    actual.on_time_finish
87  FROM android_sysui_cuj_last_cuj cuj
88  JOIN actual_frame_timeline_slice actual USING (upid)
89  JOIN android_sysui_cuj_vsync_boundaries vsync
90    ON CAST(actual.name as INTEGER) >= vsync.vsync_min
91    AND CAST(actual.name as INTEGER) <= vsync.vsync_max;
92
93-- Adjust the timestamp when we consider the work on a given frame started,
94-- by looking at the time the previous frame finished on the main thread
95-- and the timing from the actual timeline.
96-- This is to detect cases where we started doFrame late due to some other work
97-- occupying the main thread.
98DROP TABLE IF EXISTS android_sysui_cuj_do_frame_slices_in_cuj_adjusted;
99CREATE TABLE android_sysui_cuj_do_frame_slices_in_cuj_adjusted AS
100SELECT
101  slices.*,
102  CASE
103    WHEN fte.ts_expected IS NULL
104    THEN ts
105    ELSE MAX(COALESCE(slices.ts_prev_frame_end, 0), fte.ts_expected)
106  END as ts_adjusted
107FROM android_sysui_cuj_do_frame_slices_in_cuj slices
108LEFT JOIN android_sysui_cuj_frame_expected_timeline_events fte
109  ON slices.vsync = fte.vsync
110-- In rare cases there is a clock drift after device suspends
111-- This may cause the actual/expected timeline to be misaligned with the rest
112-- of the trace for a short period.
113-- Do not use the timelines if it seems that this happened.
114AND slices.ts >= fte.ts_actual_min - 1e6 AND slices.ts <= fte.ts_end_actual_max;
115
116DROP TABLE IF EXISTS android_sysui_cuj_ts_boundaries;
117CREATE TABLE android_sysui_cuj_ts_boundaries AS
118SELECT ts, ts_end - ts as dur, ts_end FROM (
119SELECT
120(SELECT ts_adjusted FROM android_sysui_cuj_do_frame_slices_in_cuj_adjusted ORDER BY ts ASC LIMIT 1) as ts,
121(SELECT ts FROM android_sysui_cuj_do_frame_slices_in_cuj ORDER BY ts DESC LIMIT 1) +
122(SELECT dur_actual FROM android_sysui_cuj_frame_timeline_events ORDER BY vsync DESC LIMIT 1) as ts_end);
123
124DROP VIEW IF EXISTS android_sysui_cuj_thread;
125CREATE VIEW android_sysui_cuj_thread AS
126SELECT
127  process.name as process_name,
128  thread.utid,
129  thread.name
130FROM thread
131JOIN android_sysui_cuj_last_cuj process USING (upid);
132
133DROP VIEW IF EXISTS android_sysui_cuj_slices_in_cuj;
134CREATE VIEW android_sysui_cuj_slices_in_cuj AS
135SELECT
136  process_name,
137  thread.utid,
138  thread.name as thread_name,
139  slices.*,
140  slices.ts + slices.dur AS ts_end
141FROM slices
142JOIN thread_track ON slices.track_id = thread_track.id
143JOIN android_sysui_cuj_thread thread USING (utid)
144JOIN android_sysui_cuj_ts_boundaries cuj_boundaries
145ON slices.ts + slices.dur >= cuj_boundaries.ts AND slices.ts <= cuj_boundaries.ts_end
146WHERE slices.dur > 0;
147
148DROP TABLE IF EXISTS android_sysui_cuj_main_thread_slices_in_cuj;
149CREATE TABLE android_sysui_cuj_main_thread_slices_in_cuj AS
150SELECT slices.* FROM android_sysui_cuj_main_thread_slices slices
151JOIN android_sysui_cuj_ts_boundaries cuj_boundaries
152ON slices.ts + slices.dur >= cuj_boundaries.ts AND slices.ts <= cuj_boundaries.ts_end;
153
154DROP TABLE IF EXISTS android_sysui_cuj_render_thread_slices_in_cuj;
155CREATE TABLE android_sysui_cuj_render_thread_slices_in_cuj AS
156SELECT slices.* FROM android_sysui_cuj_render_thread_slices slices
157JOIN android_sysui_cuj_ts_boundaries cuj_boundaries
158ON slices.ts >= cuj_boundaries.ts AND slices.ts <= cuj_boundaries.ts_end;
159
160DROP TABLE IF EXISTS android_sysui_cuj_draw_frame_slices_in_cuj;
161CREATE TABLE android_sysui_cuj_draw_frame_slices_in_cuj AS
162SELECT slices.* FROM android_sysui_cuj_draw_frame_slices slices
163JOIN android_sysui_cuj_ts_boundaries cuj_boundaries
164ON slices.ts >= cuj_boundaries.ts AND slices.ts <= cuj_boundaries.ts_end;
165
166DROP TABLE IF EXISTS android_sysui_cuj_hwc_release_slices_in_cuj;
167CREATE TABLE android_sysui_cuj_hwc_release_slices_in_cuj AS
168SELECT slices.* FROM android_sysui_cuj_hwc_release_slices slices
169JOIN android_sysui_cuj_ts_boundaries cuj_boundaries
170ON slices.ts >= cuj_boundaries.ts AND slices.ts <= cuj_boundaries.ts_end;
171
172DROP TABLE IF EXISTS android_sysui_cuj_gpu_completion_slices_in_cuj;
173CREATE TABLE android_sysui_cuj_gpu_completion_slices_in_cuj AS
174SELECT slices.* FROM android_sysui_cuj_gpu_completion_slices slices
175JOIN android_sysui_cuj_ts_boundaries cuj_boundaries
176ON slices.ts >= cuj_boundaries.ts AND slices.ts <= cuj_boundaries.ts_end;
177
178DROP TABLE IF EXISTS android_sysui_cuj_jit_slices;
179CREATE TABLE android_sysui_cuj_jit_slices AS
180SELECT *
181FROM android_sysui_cuj_slices_in_cuj
182WHERE thread_name GLOB 'Jit thread pool*'
183AND name GLOB 'JIT compiling*'
184AND parent_id IS NULL;
185
186DROP TABLE IF EXISTS android_sysui_cuj_frames;
187CREATE TABLE android_sysui_cuj_frames AS
188  WITH gcs_to_rt_match AS (
189    SELECT
190      rts.ts,
191      CASE
192        WHEN rtfence.name GLOB 'GPU completion fence *'
193          THEN CAST(STR_SPLIT(rtfence.name, ' ', 3) AS INTEGER)
194        WHEN rtfence.name GLOB 'Trace GPU completion fence *'
195          THEN CAST(STR_SPLIT(rtfence.name, ' ', 4) AS INTEGER)
196        ELSE NULL
197      END AS idx
198    FROM android_sysui_cuj_render_thread_slices_in_cuj rts
199    JOIN descendant_slice(rts.id) rtfence ON rtfence.name GLOB '*GPU completion fence*'
200    -- dispatchFrameCallbacks might be seen in case of
201    -- drawing that happens on RT only (e.g. ripple effect)
202    WHERE (rts.name GLOB 'DrawFrame*' OR rts.name = 'dispatchFrameCallbacks')
203  )
204  SELECT
205    ROW_NUMBER() OVER (ORDER BY mts.ts) AS frame_number,
206    mts.vsync as vsync,
207    -- Main thread timings
208    mts.ts_adjusted as ts_main_thread_start,
209    mts.ts_end as ts_main_thread_end,
210    mts.ts_end - mts.ts_adjusted AS dur_main_thread,
211    -- RenderThread timings
212    MIN(rts.ts) AS ts_render_thread_start,
213    MAX(rts.ts_end) AS ts_render_thread_end,
214    SUM(rts.dur) AS dur_render_thread,
215    -- HWC and GPU
216    SUM(gcs.ts_end - MAX(COALESCE(hwc.ts_end, 0), gcs.ts)) as dur_gcs,
217    -- Overall frame timings
218    COALESCE(MAX(gcs.ts_end), MAX(rts.ts_end)) AS ts_frame_end,
219    COALESCE(MAX(gcs.ts_end), MAX(rts.ts_end)) - mts.ts_adjusted AS dur_frame,
220    MAX(gcs_rt.idx) IS NOT NULL as drew_anything
221    -- Match main thread doFrame with RT DrawFrame and optional GPU Completion
222    FROM android_sysui_cuj_do_frame_slices_in_cuj_adjusted mts
223    JOIN android_sysui_cuj_draw_frame_slices_in_cuj rts
224      ON mts.vsync = rts.vsync
225    LEFT JOIN gcs_to_rt_match gcs_rt ON gcs_rt.ts = rts.ts
226    LEFT JOIN android_sysui_cuj_gpu_completion_slices_in_cuj gcs USING(idx)
227    LEFT JOIN android_sysui_cuj_hwc_release_slices_in_cuj hwc USING (idx)
228    GROUP BY mts.vsync, mts.ts_adjusted, mts.ts_end
229    HAVING drew_anything;
230
231DROP TABLE IF EXISTS android_sysui_cuj_missed_frames;
232CREATE TABLE android_sysui_cuj_missed_frames AS
233  SELECT
234    f.*,
235    (SELECT MAX(fte.app_missed)
236     FROM android_sysui_cuj_frame_timeline_events fte
237     WHERE f.vsync = fte.vsync
238     AND fte.on_time_finish = 0) as app_missed
239  FROM android_sysui_cuj_frames f;
240
241DROP VIEW IF EXISTS android_sysui_cuj_frame_main_thread_bounds;
242CREATE VIEW android_sysui_cuj_frame_main_thread_bounds AS
243SELECT frame_number, ts_main_thread_start as ts, dur_main_thread as dur
244FROM android_sysui_cuj_missed_frames
245WHERE app_missed;
246
247DROP VIEW IF EXISTS android_sysui_cuj_main_thread_state_data;
248CREATE VIEW android_sysui_cuj_main_thread_state_data AS
249SELECT * FROM thread_state
250WHERE utid = (SELECT utid FROM android_sysui_cuj_main_thread);
251
252DROP TABLE IF EXISTS android_sysui_cuj_main_thread_state_vt;
253CREATE VIRTUAL TABLE android_sysui_cuj_main_thread_state_vt
254USING span_left_join(android_sysui_cuj_frame_main_thread_bounds, android_sysui_cuj_main_thread_state_data PARTITIONED utid);
255
256DROP TABLE IF EXISTS android_sysui_cuj_main_thread_state;
257CREATE TABLE android_sysui_cuj_main_thread_state AS
258  SELECT
259    frame_number,
260    state,
261    io_wait AS io_wait,
262    SUM(dur) AS dur
263  FROM android_sysui_cuj_main_thread_state_vt
264  GROUP BY frame_number, state, io_wait
265  HAVING dur > 0;
266
267DROP VIEW IF EXISTS android_sysui_cuj_frame_render_thread_bounds;
268CREATE VIEW android_sysui_cuj_frame_render_thread_bounds AS
269SELECT frame_number, ts_render_thread_start as ts, dur_render_thread as dur
270FROM android_sysui_cuj_missed_frames
271WHERE app_missed;
272
273DROP VIEW IF EXISTS android_sysui_cuj_render_thread_state_data;
274CREATE VIEW android_sysui_cuj_render_thread_state_data AS
275SELECT * FROM thread_state
276WHERE utid in (SELECT utid FROM android_sysui_cuj_render_thread);
277
278DROP TABLE IF EXISTS android_sysui_cuj_render_thread_state_vt;
279CREATE VIRTUAL TABLE android_sysui_cuj_render_thread_state_vt
280USING span_left_join(android_sysui_cuj_frame_render_thread_bounds, android_sysui_cuj_render_thread_state_data PARTITIONED utid);
281
282DROP TABLE IF EXISTS android_sysui_cuj_render_thread_state;
283CREATE TABLE android_sysui_cuj_render_thread_state AS
284  SELECT
285    frame_number,
286    state,
287    io_wait AS io_wait,
288    SUM(dur) AS dur
289  FROM android_sysui_cuj_render_thread_state_vt
290  GROUP BY frame_number, state, io_wait
291  HAVING dur > 0;
292
293DROP TABLE IF EXISTS android_sysui_cuj_main_thread_binder;
294CREATE TABLE android_sysui_cuj_main_thread_binder AS
295  SELECT
296    f.frame_number,
297    SUM(mts.dur) AS dur,
298    COUNT(*) AS call_count
299  FROM android_sysui_cuj_missed_frames f
300  JOIN android_sysui_cuj_main_thread_slices_in_cuj mts
301    ON mts.ts >= f.ts_main_thread_start AND mts.ts < f.ts_main_thread_end
302  WHERE mts.name = 'binder transaction'
303  AND f.app_missed
304  GROUP BY f.frame_number;
305
306DROP TABLE IF EXISTS android_sysui_cuj_sf_jank_causes;
307CREATE TABLE android_sysui_cuj_sf_jank_causes AS
308  WITH RECURSIVE split_jank_type(frame_number, jank_cause, remainder) AS (
309    SELECT f.frame_number, "", fte.jank_type || ","
310    FROM android_sysui_cuj_frames f
311    JOIN android_sysui_cuj_frame_timeline_events fte ON f.vsync = fte.vsync
312    UNION ALL SELECT
313    frame_number,
314    STR_SPLIT(remainder, ",", 0) AS jank_cause,
315    TRIM(SUBSTR(remainder, INSTR(remainder, ",") + 1)) AS remainder
316    FROM split_jank_type
317    WHERE remainder <> "")
318  SELECT frame_number, jank_cause
319  FROM split_jank_type
320  WHERE jank_cause NOT IN ('', 'App Deadline Missed', 'None', 'Buffer Stuffing')
321  ORDER BY frame_number ASC;
322
323DROP TABLE IF EXISTS android_sysui_cuj_missed_frames_hwui_times;
324CREATE TABLE android_sysui_cuj_missed_frames_hwui_times AS
325SELECT
326  *,
327  ts_main_thread_start AS ts,
328  ts_render_thread_end - ts_main_thread_start AS dur
329FROM android_sysui_cuj_missed_frames;
330
331DROP TABLE IF EXISTS android_sysui_cuj_jit_slices_join_table;
332CREATE VIRTUAL TABLE android_sysui_cuj_jit_slices_join_table
333USING span_join(android_sysui_cuj_missed_frames_hwui_times partitioned frame_number, android_sysui_cuj_jit_slices);
334
335DROP TABLE IF EXISTS android_sysui_cuj_jank_causes;
336CREATE TABLE android_sysui_cuj_jank_causes AS
337  SELECT
338  frame_number,
339  'RenderThread - long shader_compile' AS jank_cause
340  FROM android_sysui_cuj_missed_frames f
341  JOIN android_sysui_cuj_render_thread_slices_in_cuj rts
342    ON rts.ts >= f.ts_render_thread_start AND rts.ts < f.ts_render_thread_end
343  WHERE rts.name = 'shader_compile'
344  AND f.app_missed
345  AND rts.dur > 8e6
346
347  UNION ALL
348  SELECT
349  frame_number,
350  'RenderThread - long flush layers' AS jank_cause
351  FROM android_sysui_cuj_missed_frames f
352  JOIN android_sysui_cuj_render_thread_slices_in_cuj rts
353    ON rts.ts >= f.ts_render_thread_start AND rts.ts < f.ts_render_thread_end
354  WHERE rts.name = 'flush layers'
355  AND rts.dur > 8e6
356  AND f.app_missed
357
358  UNION ALL
359  SELECT
360  frame_number,
361  'MainThread - IO wait time' AS jank_cause
362  FROM android_sysui_cuj_main_thread_state
363  WHERE
364    ((state = 'D' OR state = 'DK') AND io_wait)
365    OR (state = 'DK' AND io_wait IS NULL)
366  GROUP BY frame_number
367  HAVING SUM(dur) > 8e6
368
369  UNION ALL
370  SELECT
371  frame_number,
372  'MainThread - scheduler' AS jank_cause
373  FROM android_sysui_cuj_main_thread_state
374  WHERE (state = 'R' OR state = 'R+')
375  GROUP BY frame_number
376  HAVING SUM(dur) > 8e6
377  AND SUM(dur) > (
378    SELECT 0.4 * dur_main_thread
379    FROM android_sysui_cuj_frames fs
380    WHERE fs.frame_number = android_sysui_cuj_main_thread_state.frame_number)
381
382  UNION ALL
383  SELECT
384  frame_number,
385  'RenderThread - IO wait time' AS jank_cause
386  FROM android_sysui_cuj_render_thread_state
387  WHERE
388    ((state = 'D' OR state = 'DK') AND io_wait)
389    OR (state = 'DK' AND io_wait IS NULL)
390  GROUP BY frame_number
391  HAVING SUM(dur) > 8e6
392
393  UNION ALL
394  SELECT
395  frame_number,
396  'RenderThread - scheduler' AS jank_cause
397  FROM android_sysui_cuj_render_thread_state
398  WHERE (state = 'R' OR state = 'R+')
399  GROUP BY frame_number
400  HAVING SUM(dur) > 8e6
401  AND SUM(dur) > (
402    SELECT 0.4 * dur_render_thread
403    FROM android_sysui_cuj_frames fs
404    WHERE fs.frame_number = android_sysui_cuj_render_thread_state.frame_number)
405
406  UNION ALL
407  SELECT
408  frame_number,
409  'MainThread - binder transaction time' AS jank_cause
410  FROM android_sysui_cuj_main_thread_binder
411  WHERE dur > 8e6
412
413  UNION ALL
414  SELECT
415  frame_number,
416  'MainThread - binder calls count' AS jank_cause
417  FROM android_sysui_cuj_main_thread_binder
418  WHERE call_count > 8
419
420  UNION ALL
421  SELECT
422  frame_number,
423  'GPU completion - long completion time' AS jank_cause
424  FROM android_sysui_cuj_missed_frames f
425  WHERE dur_gcs > 8e6
426  AND app_missed
427
428  UNION ALL
429  SELECT
430  frame_number,
431  'Long running time' as jank_cause
432  FROM android_sysui_cuj_main_thread_state mts
433  JOIN android_sysui_cuj_render_thread_state rts USING(frame_number)
434  WHERE
435    mts.state = 'Running'
436    AND rts.state = 'Running'
437    AND mts.dur + rts.dur > 15e6
438
439  UNION ALL
440  SELECT
441  f.frame_number,
442  'JIT compiling' as jank_cause
443  FROM android_sysui_cuj_missed_frames f
444  JOIN android_sysui_cuj_jit_slices_join_table jit USING (frame_number)
445  WHERE f.app_missed
446  GROUP BY f.frame_number
447  HAVING SUM(jit.dur) > 8e6
448
449  UNION ALL
450  SELECT frame_number, jank_cause FROM android_sysui_cuj_sf_jank_causes
451  GROUP BY frame_number, jank_cause;
452
453-- TODO(b/175098682): Switch to use async slices
454DROP VIEW IF EXISTS android_sysui_cuj_event;
455CREATE VIEW android_sysui_cuj_event AS
456 SELECT
457    'slice' as track_type,
458    (SELECT cuj_name FROM android_sysui_cuj_last_cuj)
459        || ' - jank cause' as track_name,
460    f.ts_main_thread_start as ts,
461    f.dur_main_thread as dur,
462    group_concat(jc.jank_cause) as slice_name
463FROM android_sysui_cuj_frames f
464JOIN android_sysui_cuj_jank_causes jc USING (frame_number)
465GROUP BY track_type, track_name, ts, dur;
466
467DROP VIEW IF EXISTS android_sysui_cuj_output;
468CREATE VIEW android_sysui_cuj_output AS
469SELECT
470  AndroidSysUiCujMetrics(
471      'cuj_name', cuj_name,
472      'cuj_start', ts_start,
473      'cuj_dur', dur,
474      'process', process_metadata,
475      'frames',
476       (SELECT RepeatedField(
477         AndroidSysUiCujMetrics_Frame(
478           'number', f.frame_number,
479           'vsync', f.vsync,
480           'ts', f.ts_main_thread_start,
481           'dur', f.dur_frame,
482           'jank_cause',
483              (SELECT RepeatedField(jc.jank_cause)
484              FROM android_sysui_cuj_jank_causes jc WHERE jc.frame_number = f.frame_number)))
485       FROM android_sysui_cuj_frames f
486       ORDER BY frame_number ASC))
487  FROM android_sysui_cuj_last_cuj;
488