1#!/usr/bin/env python3 2# Copyright (C) 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# http://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 16from os import sys 17 18import synth_common 19 20# com.android.systemui 21PID = 1000 22# RenderThread 23RTID = 1555 24# Jit thread pool 25JITID = 1777 26LAYER = "TX - NotificationShade#0" 27 28# /system/bin/surfaceflinger 29SF_PID = 1050 30# RenderEngine thread 31SF_RETID = 1055 32 33PROCESS_TRACK = 1234 34FIRST_CUJ_TRACK = 321 35SHADE_CUJ_TRACK = 654 36CANCELED_CUJ_TRACK = 987 37 38 39def add_instant_for_track(trace, ts, track, name): 40 trace.add_track_event_slice(ts=ts, dur=0, track=track, name=name) 41 42 43def add_main_thread_atrace(trace, ts, ts_end, buf): 44 trace.add_atrace_begin(ts=ts, tid=PID, pid=PID, buf=buf) 45 trace.add_atrace_end(ts=ts_end, tid=PID, pid=PID) 46 47 48def add_render_thread_atrace_begin(trace, ts, buf): 49 trace.add_atrace_begin(ts=ts, tid=RTID, pid=PID, buf=buf) 50 51 52def add_render_thread_atrace_end(trace, ts_end): 53 trace.add_atrace_end(ts=ts_end, tid=RTID, pid=PID) 54 55 56def add_render_thread_atrace(trace, ts, ts_end, buf): 57 add_render_thread_atrace_begin(trace, ts, buf) 58 add_render_thread_atrace_end(trace, ts_end) 59 60 61def add_gpu_thread_atrace(trace, ts, ts_end, buf): 62 trace.add_atrace_begin(ts=ts, tid=1666, pid=PID, buf=buf) 63 trace.add_atrace_end(ts=ts_end, tid=1666, pid=PID) 64 65 66def add_jit_thread_atrace(trace, ts, ts_end, buf): 67 trace.add_atrace_begin(ts=ts, tid=JITID, pid=PID, buf=buf) 68 trace.add_atrace_end(ts=ts_end, tid=JITID, pid=PID) 69 70 71def add_sf_main_thread_atrace(trace, ts, ts_end, buf): 72 add_sf_main_thread_atrace_begin(trace, ts, buf) 73 add_sf_main_thread_atrace_end(trace, ts_end) 74 75 76def add_sf_main_thread_atrace_begin(trace, ts, buf): 77 trace.add_atrace_begin(ts=ts, tid=SF_PID, pid=SF_PID, buf=buf) 78 79 80def add_sf_main_thread_atrace_end(trace, ts_end): 81 trace.add_atrace_end(ts=ts_end, tid=SF_PID, pid=SF_PID) 82 83 84def add_sf_render_engine_atrace(trace, ts, ts_end, buf): 85 trace.add_atrace_begin(ts=ts, tid=SF_RETID, pid=SF_PID, buf=buf) 86 trace.add_atrace_end(ts=ts_end, tid=SF_RETID, pid=SF_PID) 87 88 89def add_frame(trace, 90 vsync, 91 ts_do_frame, 92 ts_end_do_frame, 93 ts_draw_frame, 94 ts_end_draw_frame, 95 ts_gpu=None, 96 ts_end_gpu=None, 97 resync=False): 98 add_main_thread_atrace(trace, ts_do_frame, ts_end_do_frame, 99 "Choreographer#doFrame %d" % vsync) 100 if resync: 101 add_main_thread_atrace( 102 trace, ts_do_frame, ts_end_do_frame, 103 "Choreographer#doFrame - resynced to %d in 0.0s" % (vsync + 1)) 104 gpu_idx = 1000 + vsync * 10 + 1 105 if ts_gpu is None: 106 gpu_fence_message = "GPU completion fence %d has signaled" 107 else: 108 gpu_fence_message = "Trace GPU completion fence %d" 109 add_render_thread_atrace_begin(trace, ts_draw_frame, "DrawFrames %d" % vsync) 110 add_render_thread_atrace(trace, ts_end_draw_frame - 100, 111 ts_end_draw_frame - 1, gpu_fence_message % gpu_idx) 112 add_render_thread_atrace_end(trace, ts_end_draw_frame) 113 114 if ts_gpu is not None: 115 add_gpu_thread_atrace(trace, ts_gpu, ts_end_gpu, 116 "waiting for GPU completion %d" % gpu_idx) 117 118 119def add_sf_frame(trace, 120 vsync, 121 ts_commit, 122 ts_end_commit, 123 ts_composite, 124 ts_end_composite, 125 ts_compose_surfaces=None, 126 ts_end_compose_surfaces=None): 127 add_sf_main_thread_atrace(trace, ts_commit, ts_end_commit, 128 "commit %d" % vsync) 129 add_sf_main_thread_atrace_begin(trace, ts_composite, "composite %d" % vsync) 130 if ts_compose_surfaces is not None: 131 add_sf_main_thread_atrace(trace, ts_compose_surfaces, 132 ts_end_compose_surfaces, "composeSurfaces") 133 add_sf_main_thread_atrace_end(trace, ts_end_composite) 134 135 136def add_expected_display_frame_events(ts, dur, token): 137 trace.add_expected_display_frame_start_event( 138 ts=ts, cookie=token, token=100 + token, pid=SF_PID) 139 trace.add_frame_end_event(ts=ts + dur, cookie=token) 140 141 142def add_expected_surface_frame_events(ts, dur, token): 143 trace.add_expected_surface_frame_start_event( 144 ts=ts, 145 cookie=100000 + token, 146 token=token, 147 display_frame_token=100 + token, 148 pid=PID, 149 layer_name='') 150 trace.add_frame_end_event(ts=ts + dur, cookie=100000 + token) 151 152 153def add_actual_display_frame_events(ts, dur, token, cookie=None, jank=None): 154 jank_type = jank if jank is not None else 1 155 present_type = 2 if jank is not None else 1 156 on_time_finish = 0 if jank is not None else 1 157 trace.add_actual_display_frame_start_event( 158 ts=ts, 159 cookie=token + 1, 160 token=100 + token, 161 pid=SF_PID, 162 present_type=present_type, 163 on_time_finish=on_time_finish, 164 gpu_composition=0, 165 jank_type=jank_type, 166 prediction_type=3) 167 trace.add_frame_end_event(ts=ts + dur, cookie=token + 1) 168 169 170def add_actual_surface_frame_events(ts, 171 dur, 172 token, 173 cookie=None, 174 jank=None, 175 on_time_finish_override=None, 176 display_frame_token_override=None, 177 layer_name=LAYER): 178 if cookie is None: 179 cookie = token + 1 180 jank_type = jank if jank is not None else 1 181 present_type = 2 if jank is not None else 1 182 if on_time_finish_override is None: 183 on_time_finish = 1 if jank is None else 0 184 else: 185 on_time_finish = on_time_finish_override 186 display_frame_token = display_frame_token_override or (token + 100) 187 trace.add_actual_surface_frame_start_event( 188 ts=ts, 189 cookie=100002 + cookie, 190 token=token, 191 display_frame_token=display_frame_token, 192 pid=PID, 193 present_type=present_type, 194 on_time_finish=on_time_finish, 195 gpu_composition=0, 196 jank_type=jank_type, 197 prediction_type=3, 198 layer_name=layer_name) 199 trace.add_frame_end_event(ts=ts + dur, cookie=100002 + cookie) 200 201 202trace = synth_common.create_trace() 203 204trace.add_packet() 205trace.add_package_list( 206 ts=0, name="com.android.systemui", uid=10001, version_code=1) 207trace.add_package_list(ts=0, name="android", uid=1000, version_code=1) 208trace.add_process(pid=PID, ppid=1, cmdline="com.android.systemui", uid=10001) 209trace.add_process( 210 pid=SF_PID, ppid=1, cmdline="/system/bin/surfaceflinger", uid=1000) 211trace.add_thread( 212 tid=RTID, tgid=PID, cmdline="RenderThread", name="RenderThread") 213trace.add_thread( 214 tid=1666, tgid=PID, cmdline="GPU completion", name="GPU completion") 215trace.add_thread( 216 tid=JITID, tgid=PID, cmdline="Jit thread pool", name="Jit thread pool") 217trace.add_thread( 218 tid=SF_RETID, tgid=SF_PID, cmdline="RenderEngine", name="RenderEngine") 219trace.add_process_track_descriptor(PROCESS_TRACK, pid=PID) 220trace.add_track_descriptor(FIRST_CUJ_TRACK, parent=PROCESS_TRACK) 221trace.add_track_descriptor(SHADE_CUJ_TRACK, parent=PROCESS_TRACK) 222trace.add_track_descriptor(CANCELED_CUJ_TRACK, parent=PROCESS_TRACK) 223trace.add_track_event_slice_begin( 224 ts=5, track=FIRST_CUJ_TRACK, name="J<FIRST_CUJ>") 225trace.add_track_event_slice_end(ts=100_000_000, track=FIRST_CUJ_TRACK) 226trace.add_track_event_slice_begin( 227 ts=10, track=SHADE_CUJ_TRACK, name="J<SHADE_ROW_EXPAND>") 228trace.add_track_event_slice_end(ts=901_000_010, track=SHADE_CUJ_TRACK) 229add_instant_for_track(trace, ts=11, track=SHADE_CUJ_TRACK, name="FT#layerId#0") 230add_instant_for_track( 231 trace, 232 ts=950_100_000, 233 track=SHADE_CUJ_TRACK, 234 name="FT#MissedHWUICallback#150") 235add_instant_for_track( 236 trace, 237 ts=950_100_000, 238 track=SHADE_CUJ_TRACK, 239 name="FT#MissedSFCallback#150") 240 241trace.add_track_event_slice_begin( 242 ts=100_100_000, track=CANCELED_CUJ_TRACK, name="J<CANCELED>") 243trace.add_track_event_slice_end(ts=999_000_000, track=CANCELED_CUJ_TRACK) 244trace.add_ftrace_packet(cpu=0) 245 246trace.add_atrace_counter( 247 ts=150_000_000, tid=PID, pid=PID, buf="J<FIRST_CUJ>#totalFrames", cnt=6) 248trace.add_atrace_counter( 249 ts=150_100_000, tid=PID, pid=PID, buf="J<FIRST_CUJ>#missedFrames", cnt=5) 250trace.add_atrace_counter( 251 ts=150_200_000, tid=PID, pid=PID, buf="J<FIRST_CUJ>#missedAppFrames", cnt=5) 252trace.add_atrace_counter( 253 ts=150_300_000, tid=PID, pid=PID, buf="J<FIRST_CUJ>#missedSfFrames", cnt=1) 254trace.add_atrace_counter( 255 ts=150_400_000, 256 tid=PID, 257 pid=PID, 258 buf="J<FIRST_CUJ>#maxFrameTimeMillis", 259 cnt=40) 260 261trace.add_atrace_counter( 262 ts=950_000_000, 263 tid=PID, 264 pid=PID, 265 buf="J<SHADE_ROW_EXPAND>#totalFrames", 266 cnt=13) 267trace.add_atrace_counter( 268 ts=950_100_000, 269 tid=PID, 270 pid=PID, 271 buf="J<SHADE_ROW_EXPAND>#missedFrames", 272 cnt=8) 273trace.add_atrace_counter( 274 ts=950_200_000, 275 tid=PID, 276 pid=PID, 277 buf="J<SHADE_ROW_EXPAND>#missedAppFrames", 278 cnt=7) 279trace.add_atrace_counter( 280 ts=950_300_000, 281 tid=PID, 282 pid=PID, 283 buf="J<SHADE_ROW_EXPAND>#missedSfFrames", 284 cnt=2) 285trace.add_atrace_counter( 286 ts=950_300_000, 287 tid=PID, 288 pid=PID, 289 buf="J<SHADE_ROW_EXPAND>#maxSuccessiveMissedFrames", 290 cnt=5) 291trace.add_atrace_counter( 292 ts=950_400_000, 293 tid=PID, 294 pid=PID, 295 buf="J<SHADE_ROW_EXPAND>#maxFrameTimeMillis", 296 cnt=62) 297 298add_frame( 299 trace, 300 vsync=10, 301 ts_do_frame=0, 302 ts_end_do_frame=5_000_000, 303 ts_draw_frame=4_000_000, 304 ts_end_draw_frame=5_000_000, 305 ts_gpu=10_000_000, 306 ts_end_gpu=15_000_000, 307 resync=True) 308add_main_thread_atrace( 309 trace, ts=1_500_000, ts_end=2_000_000, buf="binder transaction") 310add_render_thread_atrace( 311 trace, ts=4_500_000, ts_end=4_800_000, buf="flush layers") 312 313add_sf_frame( 314 trace, 315 vsync=110, 316 ts_commit=1_006_000_500, 317 ts_end_commit=1_006_500_000, 318 ts_composite=1_007_000_000, 319 ts_end_composite=1_008_000_000) 320 321# main thread binder call that delays the start of work on this frame 322add_sf_main_thread_atrace( 323 trace, ts=900_000_000, ts_end=1_006_000_000, buf="sf binder") 324 325add_frame( 326 trace, 327 vsync=20, 328 ts_do_frame=20_000_000, 329 ts_end_do_frame=23_000_000, 330 ts_draw_frame=22_000_000, 331 ts_end_draw_frame=26_000_000, 332 ts_gpu=27_500_000, 333 ts_end_gpu=35_000_000) 334add_main_thread_atrace( 335 trace, ts=9_000_000, ts_end=19_000_000, buf="binder transaction") 336add_render_thread_atrace( 337 trace, ts=24_000_000, ts_end=25_000_000, buf="flush layers") 338 339add_sf_frame( 340 trace, 341 vsync=120, 342 ts_commit=1_016_000_000, 343 ts_end_commit=1_018_000_000, 344 ts_composite=1_020_500_000, 345 ts_end_composite=1_025_000_000) 346 347add_frame( 348 trace, 349 vsync=30, 350 ts_do_frame=30_000_000, 351 ts_end_do_frame=33_000_000, 352 ts_draw_frame=31_000_000, 353 ts_end_draw_frame=50_000_000, 354 ts_gpu=51_500_000, 355 ts_end_gpu=52_000_000) 356add_main_thread_atrace( 357 trace, ts=31_000_000, ts_end=31_050_000, buf="binder transaction") 358add_main_thread_atrace( 359 trace, ts=31_100_000, ts_end=31_150_000, buf="binder transaction") 360add_main_thread_atrace( 361 trace, ts=31_200_000, ts_end=31_250_000, buf="binder transaction") 362add_main_thread_atrace( 363 trace, ts=31_300_000, ts_end=31_350_000, buf="binder transaction") 364add_main_thread_atrace( 365 trace, ts=31_400_000, ts_end=31_450_000, buf="binder transaction") 366add_main_thread_atrace( 367 trace, ts=31_500_000, ts_end=31_550_000, buf="binder transaction") 368add_main_thread_atrace( 369 trace, ts=31_600_000, ts_end=31_650_000, buf="binder transaction") 370add_main_thread_atrace( 371 trace, ts=31_700_000, ts_end=31_750_000, buf="binder transaction") 372add_main_thread_atrace( 373 trace, ts=31_800_000, ts_end=31_850_000, buf="binder transaction") 374add_render_thread_atrace( 375 trace, ts=38_000_000, ts_end=50_000_000, buf="flush layers") 376 377add_sf_frame( 378 trace, 379 vsync=130, 380 ts_commit=1_032_000_000, 381 ts_end_commit=1_033_000_000, 382 ts_composite=1_034_000_000, 383 ts_end_composite=1_045_000_000) 384 385add_frame( 386 trace, 387 vsync=40, 388 ts_do_frame=40_000_000, 389 ts_end_do_frame=53_000_000, 390 ts_draw_frame=52_000_000, 391 ts_end_draw_frame=59_000_000, 392 ts_gpu=66_500_000, 393 ts_end_gpu=78_000_000) 394 395add_jit_thread_atrace( 396 trace, 397 ts=39_000_000, 398 ts_end=45_000_000, 399 buf="JIT compiling void aa.aa(java.lang.Object, bb) (kind=Baseline)") 400add_jit_thread_atrace( 401 trace, 402 ts=46_000_000, 403 ts_end=47_000_000, 404 buf="Lock contention on Jit code cache (owner tid: 12345)") 405add_jit_thread_atrace( 406 trace, 407 ts=52_500_000, 408 ts_end=54_000_000, 409 buf="JIT compiling void cc.bb(java.lang.Object, bb) (kind=Osr)") 410add_jit_thread_atrace( 411 trace, 412 ts=56_500_000, 413 ts_end=60_000_000, 414 buf="JIT compiling void ff.zz(java.lang.Object, bb) (kind=Baseline)") 415 416# Main thread Running for 14 millis 417trace.add_sched(ts=39_000_000, prev_pid=0, next_pid=PID) 418trace.add_sched(ts=53_000_000, prev_pid=PID, next_pid=0, prev_state='R') 419 420# RenderThread Running for 5 millis 421trace.add_sched(ts=54_000_000, prev_pid=0, next_pid=RTID) 422trace.add_sched(ts=59_000_000, prev_pid=RTID, next_pid=0, prev_state='R') 423 424add_sf_frame( 425 trace, 426 vsync=140, 427 ts_commit=1_048_000_000, 428 ts_end_commit=1_049_000_000, 429 ts_composite=1_055_000_000, 430 ts_end_composite=1_060_000_000) 431 432add_frame( 433 trace, 434 vsync=60, 435 ts_do_frame=70_000_000, 436 ts_end_do_frame=80_000_000, 437 ts_draw_frame=78_000_000, 438 ts_end_draw_frame=87_000_000, 439 ts_gpu=86_500_000, 440 ts_end_gpu=88_000_000) 441 442# Main thread Running for 1 millis 443trace.add_sched(ts=70_000_000, prev_pid=0, next_pid=PID) 444trace.add_sched(ts=71_000_000, prev_pid=PID, next_pid=0, prev_state='R') 445 446# RenderThread Running for 1 millis and R for 9.5 millis 447trace.add_sched(ts=78_000_000, prev_pid=0, next_pid=RTID) 448trace.add_sched(ts=78_500_000, prev_pid=RTID, next_pid=0, prev_state='R') 449trace.add_sched(ts=78_500_000, prev_pid=0, next_pid=0) 450trace.add_sched(ts=88_000_000, prev_pid=0, next_pid=RTID) 451trace.add_sched(ts=88_500_000, prev_pid=RTID, next_pid=0, prev_state='R') 452 453add_sf_frame( 454 trace, 455 vsync=160, 456 ts_commit=1_070_000_000, 457 ts_end_commit=1_071_000_000, 458 ts_composite=1_072_000_000, 459 ts_end_composite=1_080_000_000) 460 461add_frame( 462 trace, 463 vsync=90, 464 ts_do_frame=100_000_000, 465 ts_end_do_frame=115_000_000, 466 ts_draw_frame=102_000_000, 467 ts_end_draw_frame=104_000_000, 468 ts_gpu=108_000_000, 469 ts_end_gpu=115_600_000) 470 471add_render_thread_atrace_begin(trace, ts=108_000_000, buf="DrawFrames 90") 472add_render_thread_atrace( 473 trace, 474 ts=113_000_000, 475 ts_end=113_500_000, 476 buf="Trace GPU completion fence 1902") 477add_render_thread_atrace_end(trace, ts_end=114_000_000) 478 479add_gpu_thread_atrace( 480 trace, 481 ts=121_500_000, 482 ts_end=122_000_000, 483 buf="waiting for GPU completion 1902") 484 485add_sf_frame( 486 trace, 487 vsync=190, 488 ts_commit=1_100_000_000, 489 ts_end_commit=1_101_000_000, 490 ts_composite=1_102_000_000, 491 ts_end_composite=1_110_000_000, 492 ts_compose_surfaces=1_104_000_000, 493 ts_end_compose_surfaces=1_108_000_000) 494 495add_sf_render_engine_atrace( 496 trace, ts=1_104_500_000, ts_end=1_107_500_000, buf="REThreaded::drawLayers") 497add_sf_render_engine_atrace( 498 trace, ts=1_105_000_000, ts_end=1_107_000_000, buf="shader compile") 499 500add_frame( 501 trace, 502 vsync=100, 503 ts_do_frame=200_000_000, 504 ts_end_do_frame=215_000_000, 505 ts_draw_frame=202_000_000, 506 ts_end_draw_frame=204_000_000, 507 ts_gpu=208_000_000, 508 ts_end_gpu=210_000_000) 509 510add_render_thread_atrace( 511 trace, ts=208_000_000, ts_end=214_000_000, buf="DrawFrames 100") 512 513add_sf_frame( 514 trace, 515 vsync=200, 516 ts_commit=1_200_000_000, 517 ts_end_commit=1_202_000_000, 518 ts_composite=1_203_000_000, 519 ts_end_composite=1_232_000_000, 520 ts_compose_surfaces=1_205_000_000, 521 ts_end_compose_surfaces=1_230_000_000) 522 523# shader compile from outside the frame that delays REThreaded::drawLayers 524add_sf_render_engine_atrace( 525 trace, ts=1_150_000_000, ts_end=1_207_000_000, buf="shader compile") 526 527add_sf_render_engine_atrace( 528 trace, ts=1_208_000_000, ts_end=1_229_000_000, buf="REThreaded::drawLayers") 529add_sf_render_engine_atrace( 530 trace, ts=1_209_000_000, ts_end=1_228_000_000, buf="shader compile") 531 532add_frame( 533 trace, 534 vsync=110, 535 ts_do_frame=300_000_000, 536 ts_end_do_frame=315_000_000, 537 ts_draw_frame=302_000_000, 538 ts_end_draw_frame=304_000_000, 539 ts_gpu=None, 540 ts_end_gpu=None) 541 542add_render_thread_atrace( 543 trace, ts=305_000_000, ts_end=308_000_000, buf="dispatchFrameCallbacks") 544 545add_frame( 546 trace, 547 vsync=120, 548 ts_do_frame=400_000_000, 549 ts_end_do_frame=415_000_000, 550 ts_draw_frame=402_000_000, 551 ts_end_draw_frame=404_000_000, 552 ts_gpu=408_000_000, 553 ts_end_gpu=410_000_000) 554 555add_render_thread_atrace( 556 trace, ts=415_000_000, ts_end=418_000_000, buf="dispatchFrameCallbacks") 557 558# Frame start delayed by 50ms by a long binder transaction 559add_main_thread_atrace( 560 trace, ts=500_000_000, ts_end=549_500_000, buf="binder transaction") 561 562add_frame( 563 trace, 564 vsync=130, 565 ts_do_frame=550_000_000, 566 ts_end_do_frame=555_000_000, 567 ts_draw_frame=552_000_000, 568 ts_end_draw_frame=556_000_000, 569 ts_gpu=None, 570 ts_end_gpu=None) 571 572# Frame start delayed by 8ms by a long binder transaction 573add_main_thread_atrace( 574 trace, ts=600_000_000, ts_end=608_049_000, buf="binder transaction") 575 576add_frame( 577 trace, 578 vsync=140, 579 ts_do_frame=608_500_000, 580 ts_end_do_frame=610_000_000, 581 ts_draw_frame=609_000_000, 582 ts_end_draw_frame=626_000_000, 583 ts_gpu=None, 584 ts_end_gpu=None) 585 586add_frame( 587 trace, 588 vsync=145, 589 ts_do_frame=655_000_000, 590 ts_end_do_frame=675_000_000, 591 ts_draw_frame=657_000_000, 592 ts_end_draw_frame=660_000_000, 593 ts_gpu=None, 594 ts_end_gpu=None) 595 596# Actual timeline slice starts 0.5ms after doFrame 597add_frame( 598 trace, 599 vsync=150, 600 ts_do_frame=700_000_000, 601 ts_end_do_frame=702_000_000, 602 ts_draw_frame=701_200_000, 603 ts_end_draw_frame=715_000_000, 604 ts_gpu=None, 605 ts_end_gpu=None) 606 607# Frame without a matching actual timeline slice 608# Skipped in `android_jank_cuj.sql` since we assume the process 609# did not draw anything. 610add_frame( 611 trace, 612 vsync=160, 613 ts_do_frame=800_000_000, 614 ts_end_do_frame=802_000_000, 615 ts_draw_frame=801_000_000, 616 ts_end_draw_frame=802_000_000, 617 ts_gpu=None, 618 ts_end_gpu=None) 619 620# One more frame after the CUJ is finished 621add_frame( 622 trace, 623 vsync=1000, 624 ts_do_frame=1_100_000_000, 625 ts_end_do_frame=1_200_000_000, 626 ts_draw_frame=1_150_000_000, 627 ts_end_draw_frame=1_300_000_000, 628 ts_gpu=1_400_000_000, 629 ts_end_gpu=1_500_000_000) 630 631add_instant_for_track( 632 trace, ts=990_000_000, track=CANCELED_CUJ_TRACK, name="FT#cancel#0") 633 634add_expected_display_frame_events(ts=1_000_000_000, dur=16_000_000, token=10) 635add_actual_display_frame_events(ts=1_000_000_000, dur=16_000_000, token=10) 636 637add_expected_surface_frame_events(ts=0, dur=16_000_000, token=10) 638add_actual_surface_frame_events(ts=0, dur=16_000_000, token=10) 639 640add_expected_display_frame_events(ts=1_016_000_000, dur=20_000_000, token=20) 641add_actual_display_frame_events(ts=1_016_000_000, dur=10_000_000, token=20) 642 643add_expected_surface_frame_events(ts=8_000_000, dur=20_000_000, token=20) 644add_actual_surface_frame_events(ts=8_000_000, dur=28_000_000, token=20, jank=66) 645 646add_expected_display_frame_events(ts=1_032_000_000, dur=16_000_000, token=30) 647add_actual_display_frame_events(ts=1_032_000_000, dur=16_000_000, token=30) 648 649add_expected_surface_frame_events(ts=30_000_000, dur=20_000_000, token=30) 650add_actual_surface_frame_events( 651 ts=30_000_000, dur=25_000_000, token=30, jank=64) 652 653add_expected_display_frame_events(ts=1_048_000_000, dur=16_000_000, token=40) 654add_actual_display_frame_events(ts=1_048_000_000, dur=16_000_000, token=40) 655 656add_expected_surface_frame_events(ts=40_000_000, dur=20_000_000, token=40) 657add_actual_surface_frame_events( 658 ts=40_000_000, dur=40_000_000, token=40, jank=64) 659 660add_expected_display_frame_events(ts=1_070_000_000, dur=16_000_000, token=60) 661add_actual_display_frame_events(ts=1_070_000_000, dur=16_000_000, token=60) 662 663add_expected_surface_frame_events(ts=70_000_000, dur=20_000_000, token=60) 664add_actual_surface_frame_events( 665 ts=70_000_000, dur=10_000_000, token=60, jank=64) 666add_actual_surface_frame_events( 667 ts=70_000_000, 668 dur=20_000_000, 669 token=60, 670 cookie=62, 671 jank=64, 672 # second layer produced frame later so was picked up by the next SF frame 673 display_frame_token_override=190) 674 675add_expected_display_frame_events(ts=1_100_000_000, dur=16_000_000, token=90) 676add_actual_display_frame_events(ts=1_100_000_000, dur=16_000_000, token=90) 677 678add_expected_surface_frame_events(ts=100_000_000, dur=20_000_000, token=90) 679add_actual_surface_frame_events( 680 ts=100_000_000, dur=23_000_000, token=90, jank=64) 681 682add_expected_display_frame_events(ts=1_200_000_000, dur=16_000_000, token=100) 683add_actual_display_frame_events( 684 ts=1_200_000_000, dur=32_000_000, token=100, jank=16) 685 686add_expected_surface_frame_events(ts=200_000_000, dur=20_000_000, token=100) 687add_actual_surface_frame_events( 688 ts=200_000_000, dur=22_000_000, token=100, jank=34) 689 690add_expected_surface_frame_events(ts=300_000_000, dur=20_000_000, token=110) 691add_actual_surface_frame_events( 692 ts=300_000_000, cookie=112, dur=61_000_000, token=110) 693add_actual_surface_frame_events( 694 ts=300_000_000, 695 cookie=114, 696 dur=80_000_000, 697 token=110, 698 jank=64, 699 layer_name="TX - JankyLayer#1") 700 701add_expected_surface_frame_events(ts=400_000_000, dur=20_000_000, token=120) 702add_actual_surface_frame_events( 703 ts=400_000_000, 704 dur=61_000_000, 705 token=120, 706 jank=128, 707 on_time_finish_override=1) 708 709# Multiple layers but only one of them janked (the one we care about) 710add_expected_surface_frame_events(ts=500_000_000, dur=20_000_000, token=130) 711add_actual_surface_frame_events(ts=500_000_000, dur=2_000_000, token=130) 712add_actual_surface_frame_events( 713 ts=550_000_000, dur=6_000_000, token=130, cookie=132, jank=64) 714 715# Single layer but actual frame event is slighly after doFrame start 716add_expected_surface_frame_events(ts=600_000_000, dur=20_000_000, token=140) 717add_actual_surface_frame_events( 718 ts=608_600_000, dur=17_000_000, token=140, jank=64) 719 720# Surface flinger stuffing frame not classified as missed 721add_expected_surface_frame_events(ts=650_000_000, dur=20_000_000, token=145) 722add_actual_surface_frame_events( 723 ts=650_000_000, dur=20_000_000, token=145, jank=512) 724 725add_expected_surface_frame_events(ts=700_000_000, dur=20_000_000, token=150) 726add_actual_surface_frame_events(ts=700_500_000, dur=14_500_000, token=150) 727 728# No matching actual timeline 729add_expected_surface_frame_events(ts=800_000_000, dur=20_000_000, token=160) 730 731add_expected_surface_frame_events(ts=1_100_000_000, dur=20_000_000, token=1000) 732add_actual_surface_frame_events( 733 ts=1_100_000_000, dur=500_000_000, token=1000, jank=64) 734 735sys.stdout.buffer.write(trace.trace.SerializeToString()) 736