Results for igt@kms_flip@plain-flip-ts-check@a-hdmi-a3

Result: Fail

git-log-oneline i915_display_info21 igt_runner21 runtimes21 results21.json results21-i915-load.json guc_logs21.tar i915_display_info_post_exec21 boot21 dmesg21

DetailValue
Duration 18.98 seconds
Hostname
shard-dg2-5
Igt-Version
IGT-Version: 2.4-g605045432 (x86_64) (Linux: 7.0.0-rc6-CI_DRM_18281-gd873f0156bd0+ x86_64)
Out
Using IGT_SRANDOM=1775469772 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: plain-flip-ts-check
Starting dynamic subtest: A-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Expected frametime: 16667us; measured 16667.6us +- 6.000us accuracy 0.11%
Event flip: expected 450, counted 440, passrate = 18.64%, encoder type 2
Expected frametime: 16667us; measured 16871.7us +- 9.149us accuracy 0.16%
vblank interval differs from modeline! expected 16666.7us, measured 16872us +- 9.149us, difference 205.0us (22.4 sigma)
Event flip: expected 445, counted 447, passrate = 54.81%, encoder type 2
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1891 run_test()
  #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047()
  #4 ../tests/kms_flip.c:2047 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A3: FAIL (18.976s)
Err
Starting subtest: plain-flip-ts-check
Starting dynamic subtest: A-HDMI-A3
(kms_flip:2377) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1711:
(kms_flip:2377) CRITICAL: Failed assertion: !retried
Dynamic subtest A-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:2377) DEBUG: flip ts/seq: last 303.695374/6328, current 303.712128/6329: elapsed=16754.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.695374/6328, current 303.712128/6329: elapsed=16754.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.712128
last_received_ts = 303.711792
last_seq = 6329
current_ts = 303.728912
current_received_ts = 303.728607
current_seq = 6330
count = 367
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.712128/6329, current 303.728912/6330: elapsed=16777.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.712128/6329, current 303.728912/6330: elapsed=16777.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.728912
last_received_ts = 303.728607
last_seq = 6330
current_ts = 303.745667
current_received_ts = 303.745300
current_seq = 6331
count = 368
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.728912/6330, current 303.745667/6331: elapsed=16757.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.728912/6330, current 303.745667/6331: elapsed=16757.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.745667
last_received_ts = 303.745300
last_seq = 6331
current_ts = 303.762451
current_received_ts = 303.762177
current_seq = 6332
count = 369
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.745667/6331, current 303.762451/6332: elapsed=16763.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.745667/6331, current 303.762451/6332: elapsed=16763.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.762451
last_received_ts = 303.762177
last_seq = 6332
current_ts = 303.779205
current_received_ts = 303.778900
current_seq = 6333
count = 370
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.762451/6332, current 303.779205/6333: elapsed=16764.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.762451/6332, current 303.779205/6333: elapsed=16764.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.779205
last_received_ts = 303.778900
last_seq = 6333
current_ts = 303.795959
current_received_ts = 303.795654
current_seq = 6334
count = 371
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.779205/6333, current 303.795959/6334: elapsed=16761.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.779205/6333, current 303.795959/6334: elapsed=16761.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.795959
last_received_ts = 303.795654
last_seq = 6334
current_ts = 303.812744
current_received_ts = 303.812408
current_seq = 6335
count = 372
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.795959/6334, current 303.812744/6335: elapsed=16765.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.795959/6334, current 303.812744/6335: elapsed=16765.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.812744
last_received_ts = 303.812408
last_seq = 6335
current_ts = 303.829498
current_received_ts = 303.829193
current_seq = 6336
count = 373
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.812744/6335, current 303.829498/6336: elapsed=16762.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.812744/6335, current 303.829498/6336: elapsed=16762.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.829498
last_received_ts = 303.829193
last_seq = 6336
current_ts = 303.846252
current_received_ts = 303.845886
current_seq = 6337
count = 374
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.829498/6336, current 303.846252/6337: elapsed=16757.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.829498/6336, current 303.846252/6337: elapsed=16757.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.846252
last_received_ts = 303.845886
last_seq = 6337
current_ts = 303.863037
current_received_ts = 303.862732
current_seq = 6338
count = 375
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.846252/6337, current 303.863037/6338: elapsed=16778.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.846252/6337, current 303.863037/6338: elapsed=16778.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.863037
last_received_ts = 303.862732
last_seq = 6338
current_ts = 303.879761
current_received_ts = 303.879364
current_seq = 6339
count = 376
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.863037/6338, current 303.879761/6339: elapsed=16750.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.863037/6338, current 303.879761/6339: elapsed=16750.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.879761
last_received_ts = 303.879364
last_seq = 6339
current_ts = 303.896545
current_received_ts = 303.896179
current_seq = 6340
count = 377
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.879761/6339, current 303.896545/6340: elapsed=16763.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.879761/6339, current 303.896545/6340: elapsed=16763.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.896545
last_received_ts = 303.896179
last_seq = 6340
current_ts = 303.913330
current_received_ts = 303.912933
current_seq = 6341
count = 378
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.896545/6340, current 303.913330/6341: elapsed=16777.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.896545/6340, current 303.913330/6341: elapsed=16777.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.913330
last_received_ts = 303.912933
last_seq = 6341
current_ts = 303.930084
current_received_ts = 303.929688
current_seq = 6342
count = 379
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.913330/6341, current 303.930084/6342: elapsed=16761.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.913330/6341, current 303.930084/6342: elapsed=16761.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.930084
last_received_ts = 303.929688
last_seq = 6342
current_ts = 303.946838
current_received_ts = 303.946442
current_seq = 6343
count = 380
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.930084/6342, current 303.946838/6343: elapsed=16752.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.930084/6342, current 303.946838/6343: elapsed=16752.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.946838
last_received_ts = 303.946442
last_seq = 6343
current_ts = 303.963593
current_received_ts = 303.963226
current_seq = 6344
count = 381
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.946838/6343, current 303.963593/6344: elapsed=16770.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.946838/6343, current 303.963593/6344: elapsed=16770.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.963593
last_received_ts = 303.963226
last_seq = 6344
current_ts = 303.980347
current_received_ts = 303.979980
current_seq = 6345
count = 382
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.963593/6344, current 303.980347/6345: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.963593/6344, current 303.980347/6345: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.980347
last_received_ts = 303.979980
last_seq = 6345
current_ts = 303.997131
current_received_ts = 303.996735
current_seq = 6346
count = 383
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.980347/6345, current 303.997131/6346: elapsed=16772.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.980347/6345, current 303.997131/6346: elapsed=16772.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 303.997131
last_received_ts = 303.996735
last_seq = 6346
current_ts = 304.013885
current_received_ts = 304.013519
current_seq = 6347
count = 384
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 303.997131/6346, current 304.013885/6347: elapsed=16743.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 303.997131/6346, current 304.013885/6347: elapsed=16743.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.013885
last_received_ts = 304.013519
last_seq = 6347
current_ts = 304.030640
current_received_ts = 304.030273
current_seq = 6348
count = 385
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.013885/6347, current 304.030640/6348: elapsed=16753.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.013885/6347, current 304.030640/6348: elapsed=16753.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.030640
last_received_ts = 304.030273
last_seq = 6348
current_ts = 304.047394
current_received_ts = 304.047119
current_seq = 6349
count = 386
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.030640/6348, current 304.047394/6349: elapsed=16754.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.030640/6348, current 304.047394/6349: elapsed=16754.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.047394
last_received_ts = 304.047119
last_seq = 6349
current_ts = 304.064117
current_received_ts = 304.063751
current_seq = 6350
count = 387
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.047394/6349, current 304.064117/6350: elapsed=16745.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.047394/6349, current 304.064117/6350: elapsed=16745.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.064117
last_received_ts = 304.063751
last_seq = 6350
current_ts = 304.080872
current_received_ts = 304.080566
current_seq = 6351
count = 388
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.064117/6350, current 304.080872/6351: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.064117/6350, current 304.080872/6351: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.080872
last_received_ts = 304.080566
last_seq = 6351
current_ts = 304.097626
current_received_ts = 304.097290
current_seq = 6352
count = 389
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.080872/6351, current 304.097626/6352: elapsed=16755.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.080872/6351, current 304.097626/6352: elapsed=16755.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.097626
last_received_ts = 304.097290
last_seq = 6352
current_ts = 304.114380
current_received_ts = 304.114136
current_seq = 6353
count = 390
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.097626/6352, current 304.114380/6353: elapsed=16749.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.097626/6352, current 304.114380/6353: elapsed=16749.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.114380
last_received_ts = 304.114136
last_seq = 6353
current_ts = 304.131134
current_received_ts = 304.130859
current_seq = 6354
count = 391
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.114380/6353, current 304.131134/6354: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.114380/6353, current 304.131134/6354: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.131134
last_received_ts = 304.130859
last_seq = 6354
current_ts = 304.147888
current_received_ts = 304.147522
current_seq = 6355
count = 392
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.131134/6354, current 304.147888/6355: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.131134/6354, current 304.147888/6355: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.147888
last_received_ts = 304.147522
last_seq = 6355
current_ts = 304.164642
current_received_ts = 304.164276
current_seq = 6356
count = 393
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.147888/6355, current 304.164642/6356: elapsed=16749.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.147888/6355, current 304.164642/6356: elapsed=16749.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.164642
last_received_ts = 304.164276
last_seq = 6356
current_ts = 304.181396
current_received_ts = 304.181122
current_seq = 6357
count = 394
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.164642/6356, current 304.181396/6357: elapsed=16751.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.164642/6356, current 304.181396/6357: elapsed=16751.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.181396
last_received_ts = 304.181122
last_seq = 6357
current_ts = 304.198151
current_received_ts = 304.197876
current_seq = 6358
count = 395
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.181396/6357, current 304.198151/6358: elapsed=16757.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.181396/6357, current 304.198151/6358: elapsed=16757.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.198151
last_received_ts = 304.197876
last_seq = 6358
current_ts = 304.214905
current_received_ts = 304.214508
current_seq = 6359
count = 396
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.198151/6358, current 304.214905/6359: elapsed=16741.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.198151/6358, current 304.214905/6359: elapsed=16741.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.214905
last_received_ts = 304.214508
last_seq = 6359
current_ts = 304.231659
current_received_ts = 304.231323
current_seq = 6360
count = 397
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.214905/6359, current 304.231659/6360: elapsed=16763.0us expected=16871.7us +- 84.4us, error 0.6%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.214905/6359, current 304.231659/6360: elapsed=16763.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.231659
last_received_ts = 304.231323
last_seq = 6360
current_ts = 304.248413
current_received_ts = 304.248047
current_seq = 6361
count = 398
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.231659/6360, current 304.248413/6361: elapsed=16740.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.231659/6360, current 304.248413/6361: elapsed=16740.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.248413
last_received_ts = 304.248047
last_seq = 6361
current_ts = 304.265167
current_received_ts = 304.264862
current_seq = 6362
count = 399
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.248413/6361, current 304.265167/6362: elapsed=16757.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.248413/6361, current 304.265167/6362: elapsed=16757.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.265167
last_received_ts = 304.264862
last_seq = 6362
current_ts = 304.281921
current_received_ts = 304.281433
current_seq = 6363
count = 400
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.265167/6362, current 304.281921/6363: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.265167/6362, current 304.281921/6363: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.281921
last_received_ts = 304.281433
last_seq = 6363
current_ts = 304.298676
current_received_ts = 304.298309
current_seq = 6364
count = 401
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.281921/6363, current 304.298676/6364: elapsed=16746.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.281921/6363, current 304.298676/6364: elapsed=16746.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.298676
last_received_ts = 304.298309
last_seq = 6364
current_ts = 304.315399
current_received_ts = 304.315125
current_seq = 6365
count = 402
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.298676/6364, current 304.315399/6365: elapsed=16752.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.298676/6364, current 304.315399/6365: elapsed=16752.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.315399
last_received_ts = 304.315125
last_seq = 6365
current_ts = 304.332184
current_received_ts = 304.331879
current_seq = 6366
count = 403
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.315399/6365, current 304.332184/6366: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.315399/6365, current 304.332184/6366: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.332184
last_received_ts = 304.331879
last_seq = 6366
current_ts = 304.348907
current_received_ts = 304.348511
current_seq = 6367
count = 404
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.332184/6366, current 304.348907/6367: elapsed=16747.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.332184/6366, current 304.348907/6367: elapsed=16747.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.348907
last_received_ts = 304.348511
last_seq = 6367
current_ts = 304.365662
current_received_ts = 304.365295
current_seq = 6368
count = 405
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.348907/6367, current 304.365662/6368: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.348907/6367, current 304.365662/6368: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.365662
last_received_ts = 304.365295
last_seq = 6368
current_ts = 304.382446
current_received_ts = 304.382080
current_seq = 6369
count = 406
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.365662/6368, current 304.382446/6369: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.365662/6368, current 304.382446/6369: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.382446
last_received_ts = 304.382080
last_seq = 6369
current_ts = 304.399170
current_received_ts = 304.398804
current_seq = 6370
count = 407
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.382446/6369, current 304.399170/6370: elapsed=16741.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.382446/6369, current 304.399170/6370: elapsed=16741.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.399170
last_received_ts = 304.398804
last_seq = 6370
current_ts = 304.415924
current_received_ts = 304.415527
current_seq = 6371
count = 408
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.399170/6370, current 304.415924/6371: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.399170/6370, current 304.415924/6371: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.415924
last_received_ts = 304.415527
last_seq = 6371
current_ts = 304.432678
current_received_ts = 304.432434
current_seq = 6372
count = 409
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.415924/6371, current 304.432678/6372: elapsed=16755.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.415924/6371, current 304.432678/6372: elapsed=16755.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.432678
last_received_ts = 304.432434
last_seq = 6372
current_ts = 304.449432
current_received_ts = 304.449158
current_seq = 6373
count = 410
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.432678/6372, current 304.449432/6373: elapsed=16750.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.432678/6372, current 304.449432/6373: elapsed=16750.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.449432
last_received_ts = 304.449158
last_seq = 6373
current_ts = 304.466187
current_received_ts = 304.465912
current_seq = 6374
count = 411
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.449432/6373, current 304.466187/6374: elapsed=16755.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.449432/6373, current 304.466187/6374: elapsed=16755.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.466187
last_received_ts = 304.465912
last_seq = 6374
current_ts = 304.482941
current_received_ts = 304.482513
current_seq = 6375
count = 412
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.466187/6374, current 304.482941/6375: elapsed=16752.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.466187/6374, current 304.482941/6375: elapsed=16752.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.482941
last_received_ts = 304.482513
last_seq = 6375
current_ts = 304.499695
current_received_ts = 304.499329
current_seq = 6376
count = 413
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.482941/6375, current 304.499695/6376: elapsed=16752.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.482941/6375, current 304.499695/6376: elapsed=16752.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.499695
last_received_ts = 304.499329
last_seq = 6376
current_ts = 304.516449
current_received_ts = 304.516235
current_seq = 6377
count = 414
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.499695/6376, current 304.516449/6377: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.499695/6376, current 304.516449/6377: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.516449
last_received_ts = 304.516235
last_seq = 6377
current_ts = 304.533203
current_received_ts = 304.532806
current_seq = 6378
count = 415
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.516449/6377, current 304.533203/6378: elapsed=16742.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.516449/6377, current 304.533203/6378: elapsed=16742.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.533203
last_received_ts = 304.532806
last_seq = 6378
current_ts = 304.549957
current_received_ts = 304.549561
current_seq = 6379
count = 416
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.533203/6378, current 304.549957/6379: elapsed=16753.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.533203/6378, current 304.549957/6379: elapsed=16753.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.549957
last_received_ts = 304.549561
last_seq = 6379
current_ts = 304.566711
current_received_ts = 304.566437
current_seq = 6380
count = 417
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.549957/6379, current 304.566711/6380: elapsed=16754.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.549957/6379, current 304.566711/6380: elapsed=16754.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.566711
last_received_ts = 304.566437
last_seq = 6380
current_ts = 304.583466
current_received_ts = 304.583191
current_seq = 6381
count = 418
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.566711/6380, current 304.583466/6381: elapsed=16755.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.566711/6380, current 304.583466/6381: elapsed=16755.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.583466
last_received_ts = 304.583191
last_seq = 6381
current_ts = 304.600220
current_received_ts = 304.599915
current_seq = 6382
count = 419
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.583466/6381, current 304.600220/6382: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.583466/6381, current 304.600220/6382: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.600220
last_received_ts = 304.599915
last_seq = 6382
current_ts = 304.616974
current_received_ts = 304.616577
current_seq = 6383
count = 420
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.600220/6382, current 304.616974/6383: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.600220/6382, current 304.616974/6383: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.616974
last_received_ts = 304.616577
last_seq = 6383
current_ts = 304.633728
current_received_ts = 304.633423
current_seq = 6384
count = 421
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.616974/6383, current 304.633728/6384: elapsed=16747.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.616974/6383, current 304.633728/6384: elapsed=16747.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.633728
last_received_ts = 304.633423
last_seq = 6384
current_ts = 304.650452
current_received_ts = 304.650116
current_seq = 6385
count = 422
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.633728/6384, current 304.650452/6385: elapsed=16749.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.633728/6384, current 304.650452/6385: elapsed=16749.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.650452
last_received_ts = 304.650116
last_seq = 6385
current_ts = 304.667206
current_received_ts = 304.666931
current_seq = 6386
count = 423
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.650452/6385, current 304.667206/6386: elapsed=16757.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.650452/6385, current 304.667206/6386: elapsed=16757.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.667206
last_received_ts = 304.666931
last_seq = 6386
current_ts = 304.683960
current_received_ts = 304.683563
current_seq = 6387
count = 424
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.667206/6386, current 304.683960/6387: elapsed=16747.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.667206/6386, current 304.683960/6387: elapsed=16747.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.683960
last_received_ts = 304.683563
last_seq = 6387
current_ts = 304.700714
current_received_ts = 304.700317
current_seq = 6388
count = 425
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.683960/6387, current 304.700714/6388: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.683960/6387, current 304.700714/6388: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.700714
last_received_ts = 304.700317
last_seq = 6388
current_ts = 304.717468
current_received_ts = 304.717194
current_seq = 6389
count = 426
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.700714/6388, current 304.717468/6389: elapsed=16751.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.700714/6388, current 304.717468/6389: elapsed=16751.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.717468
last_received_ts = 304.717194
last_seq = 6389
current_ts = 304.734222
current_received_ts = 304.733948
current_seq = 6390
count = 427
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.717468/6389, current 304.734222/6390: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.717468/6389, current 304.734222/6390: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.734222
last_received_ts = 304.733948
last_seq = 6390
current_ts = 304.750977
current_received_ts = 304.750671
current_seq = 6391
count = 428
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.734222/6390, current 304.750977/6391: elapsed=16749.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.734222/6390, current 304.750977/6391: elapsed=16749.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.750977
last_received_ts = 304.750671
last_seq = 6391
current_ts = 304.767731
current_received_ts = 304.767303
current_seq = 6392
count = 429
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.750977/6391, current 304.767731/6392: elapsed=16757.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.750977/6391, current 304.767731/6392: elapsed=16757.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.767731
last_received_ts = 304.767303
last_seq = 6392
current_ts = 304.784485
current_received_ts = 304.784210
current_seq = 6393
count = 430
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.767731/6392, current 304.784485/6393: elapsed=16751.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.767731/6392, current 304.784485/6393: elapsed=16751.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.784485
last_received_ts = 304.784210
last_seq = 6393
current_ts = 304.801239
current_received_ts = 304.800842
current_seq = 6394
count = 431
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.784485/6393, current 304.801239/6394: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.784485/6393, current 304.801239/6394: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.801239
last_received_ts = 304.800842
last_seq = 6394
current_ts = 304.817993
current_received_ts = 304.817688
current_seq = 6395
count = 432
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.801239/6394, current 304.817993/6395: elapsed=16748.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.801239/6394, current 304.817993/6395: elapsed=16748.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.817993
last_received_ts = 304.817688
last_seq = 6395
current_ts = 304.834747
current_received_ts = 304.834412
current_seq = 6396
count = 433
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.817993/6395, current 304.834747/6396: elapsed=16747.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.817993/6395, current 304.834747/6396: elapsed=16747.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.834747
last_received_ts = 304.834412
last_seq = 6396
current_ts = 304.851501
current_received_ts = 304.851135
current_seq = 6397
count = 434
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.834747/6396, current 304.851501/6397: elapsed=16751.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.834747/6396, current 304.851501/6397: elapsed=16751.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.851501
last_received_ts = 304.851135
last_seq = 6397
current_ts = 304.868256
current_received_ts = 304.867981
current_seq = 6398
count = 435
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.851501/6397, current 304.868256/6398: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.851501/6397, current 304.868256/6398: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.868256
last_received_ts = 304.867981
last_seq = 6398
current_ts = 304.885010
current_received_ts = 304.884613
current_seq = 6399
count = 436
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.868256/6398, current 304.885010/6399: elapsed=16758.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.868256/6398, current 304.885010/6399: elapsed=16758.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.885010
last_received_ts = 304.884613
last_seq = 6399
current_ts = 304.901764
current_received_ts = 304.901306
current_seq = 6400
count = 437
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.885010/6399, current 304.901764/6400: elapsed=16744.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.885010/6399, current 304.901764/6400: elapsed=16744.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.901764
last_received_ts = 304.901306
last_seq = 6400
current_ts = 304.918518
current_received_ts = 304.918243
current_seq = 6401
count = 438
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.901764/6400, current 304.918518/6401: elapsed=16754.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.901764/6400, current 304.918518/6401: elapsed=16754.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.918518
last_received_ts = 304.918243
last_seq = 6401
current_ts = 304.935272
current_received_ts = 304.934875
current_seq = 6402
count = 439
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.918518/6401, current 304.935272/6402: elapsed=16759.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.918518/6401, current 304.935272/6402: elapsed=16759.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.935272
last_received_ts = 304.934875
last_seq = 6402
current_ts = 304.951996
current_received_ts = 304.951721
current_seq = 6403
count = 440
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.935272/6402, current 304.951996/6403: elapsed=16747.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.935272/6402, current 304.951996/6403: elapsed=16747.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.951996
last_received_ts = 304.951721
last_seq = 6403
current_ts = 304.968781
current_received_ts = 304.968323
current_seq = 6404
count = 441
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.951996/6403, current 304.968781/6404: elapsed=16756.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.951996/6403, current 304.968781/6404: elapsed=16756.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.968781
last_received_ts = 304.968323
last_seq = 6404
current_ts = 304.985504
current_received_ts = 304.985260
current_seq = 6405
count = 442
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.968781/6404, current 304.985504/6405: elapsed=16746.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.968781/6404, current 304.985504/6405: elapsed=16746.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 304.985504
last_received_ts = 304.985260
last_seq = 6405
current_ts = 305.002258
current_received_ts = 305.001892
current_seq = 6406
count = 443
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 304.985504/6405, current 305.002258/6406: elapsed=16743.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 304.985504/6405, current 305.002258/6406: elapsed=16743.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 305.002258
last_received_ts = 305.001892
last_seq = 6406
current_ts = 305.019012
current_received_ts = 305.018616
current_seq = 6407
count = 444
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 305.002258/6406, current 305.019012/6407: elapsed=16754.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 305.002258/6406, current 305.019012/6407: elapsed=16754.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 305.019012
last_received_ts = 305.018616
last_seq = 6407
current_ts = 305.035736
current_received_ts = 305.035400
current_seq = 6408
count = 445
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 305.019012/6407, current 305.035736/6408: elapsed=16731.0us expected=16871.7us +- 84.4us, error 0.8%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 305.019012/6407, current 305.035736/6408: elapsed=16731.0us expected=16871.7us
(kms_flip:2377) DEBUG: name = flip
last_ts = 305.035736
last_received_ts = 305.035400
last_seq = 6408
current_ts = 305.052490
current_received_ts = 305.052246
current_seq = 6409
count = 446
seq_step = 1
(kms_flip:2377) DEBUG: flip ts/seq: last 305.035736/6408, current 305.052490/6409: elapsed=16751.0us expected=16871.7us +- 84.4us, error 0.7%
(kms_flip:2377) DEBUG: inconsistent flip ts/seq: last 305.035736/6408, current 305.052490/6409: elapsed=16751.0us expected=16871.7us
(kms_flip:2377) INFO: Event flip: expected 445, counted 447, passrate = 54.81%, encoder type 2
(kms_flip:2377) DEBUG: dropped frames, expected 445, counted 447, passrate = 54.81%, encoder type 2
(kms_flip:2377) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1711:
(kms_flip:2377) CRITICAL: Failed assertion: !retried
(kms_flip:2377) igt_core-INFO: Stack trace:
(kms_flip:2377) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2377) igt_core-INFO:   #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
(kms_flip:2377) igt_core-INFO:   #2 ../tests/kms_flip.c:1891 run_test()
(kms_flip:2377) igt_core-INFO:   #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047()
(kms_flip:2377) igt_core-INFO:   #4 ../tests/kms_flip.c:2047 main()
(kms_flip:2377) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2377) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2377) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A3: FAIL (18.976s)
Dmesg
<6> [284.607651] Console: switching to colour dummy device 80x25
<6> [284.608146] [IGT] kms_flip: executing
<7> [284.621723] i915 0000:03:00.0: [drm:i915_gem_open [i915]]
<7> [284.623607] i915 0000:03:00.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x000001dc [0x000001dc]
<7> [284.633554] i915 0000:03:00.0: [drm:i915_gem_open [i915]]
<7> [284.642203] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:508:DP-1]
<7> [284.642210] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:508:DP-1]
<7> [284.646538] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:508:DP-1] disconnected
<7> [284.646887] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:521:DP-2]
<7> [284.646892] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:521:DP-2]
<7> [284.651148] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:521:DP-2] disconnected
<7> [284.651564] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:530:HDMI-A-1]
<7> [284.651569] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:530:HDMI-A-1]
<7> [284.655821] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:530:HDMI-A-1] disconnected
<7> [284.656175] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:536:DP-3]
<7> [284.656180] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:536:DP-3]
<7> [284.660437] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:536:DP-3] disconnected
<7> [284.660793] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:544:HDMI-A-2]
<7> [284.660798] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:544:HDMI-A-2]
<7> [284.665060] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:544:HDMI-A-2] disconnected
<7> [284.665463] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:548:DP-4]
<7> [284.665467] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:548:DP-4]
<7> [284.665739] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling AUX_D
<7> [284.688027] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.709177] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.730317] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.751451] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.772580] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.793740] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.814899] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.836058] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.857251] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.878412] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.899569] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.920729] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.941885] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.963041] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [284.984212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.005372] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.026534] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.047693] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.068854] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.090013] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.111202] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.132367] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.153576] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.174726] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.195887] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.217047] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.238257] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.259419] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.280578] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.301736] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.322905] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.344055] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.344273] i915 0000:03:00.0: [drm:drm_dp_dpcd_access [drm_display_helper]] AUX D/DDI D/PHY D: Too many retries, giving up. First error: -110
<7> [285.344344] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:548:DP-4] disconnected
<7> [285.345050] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:508:DP-1]
<7> [285.345055] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:508:DP-1]
<7> [285.349396] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:508:DP-1] disconnected
<7> [285.349411] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:521:DP-2]
<7> [285.349415] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:521:DP-2]
<7> [285.353629] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:521:DP-2] disconnected
<7> [285.353643] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:530:HDMI-A-1]
<7> [285.353647] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:530:HDMI-A-1]
<7> [285.357903] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:530:HDMI-A-1] disconnected
<7> [285.357918] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:536:DP-3]
<7> [285.357921] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:536:DP-3]
<7> [285.362134] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:536:DP-3] disconnected
<7> [285.362148] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:544:HDMI-A-2]
<7> [285.362152] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:544:HDMI-A-2]
<7> [285.366454] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:544:HDMI-A-2] disconnected
<7> [285.366468] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:548:DP-4]
<7> [285.366472] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:548:DP-4]
<7> [285.387587] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.408707] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.429854] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.450996] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.472139] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.493304] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.514478] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.535643] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.556795] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.577953] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.599109] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.620272] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.641434] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.662586] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.683745] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.704913] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.726073] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.747268] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.768440] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.789595] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.810753] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.831895] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.853052] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.874261] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.895433] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.916603] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.937759] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.958913] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [285.980069] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [286.001233] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [286.022393] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [286.043551] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [286.043769] i915 0000:03:00.0: [drm:drm_dp_dpcd_access [drm_display_helper]] AUX D/DDI D/PHY D: Too many retries, giving up. First error: -110
<7> [286.043814] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:548:DP-4] disconnected
<7> [286.043833] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:556:HDMI-A-3]
<7> [286.043838] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [286.068767] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:556:HDMI-A-3] ELD monitor FH-DP4K
<7> [286.068773] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:556:HDMI-A-3] ELD size 36, SAD count 2
<7> [286.068942] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpd] NAK for addr: 0040 w(1)
<7> [286.069131] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpd] NAK on first message, retry
<7> [286.069466] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpd] NAK for addr: 0040 w(1)
<7> [286.069670] i915 0000:03:00.0: [drm:drm_dp_dual_mode_detect [drm_display_helper]] DP dual mode HDMI ID: (err -6)
<7> [286.069684] i915 0000:03:00.0: [drm:intel_hdmi_set_edid [i915]] Assuming DP dual mode adaptor presence based on VBT
<7> [286.069866] i915 0000:03:00.0: [drm:intel_hdmi_set_edid [i915]] DP dual mode adaptor (type 1 DVI) detected (max TMDS clock: 165000 kHz)
<7> [286.070631] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "2560x1440": 60 241700 2560 2608 2640 2720 1440 1443 1448 1481 0x40 0x9 (CLOCK_HIGH)
<7> [286.070639] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "2560x1600": 60 267820 2560 2608 2640 2720 1600 1603 1608 1641 0x40 0x9 (CLOCK_HIGH)
<7> [286.070645] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080": 120 297000 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 (CLOCK_HIGH)
<7> [286.070651] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "3840x2160": 30 266640 3840 3888 3920 4000 2160 2163 2168 2222 0x40 0x9 (CLOCK_HIGH)
<7> [286.070656] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080": 120 296703 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 (CLOCK_HIGH)
<7> [286.070663] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:556:HDMI-A-3] probed modes:
<7> [286.070666] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [286.070670] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "3840x2160": 17 151100 3840 3888 3920 4000 2160 2163 2168 2222 0x40 0x9
<7> [286.070673] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1600": 30 133910 2560 2608 2640 2720 1600 1603 1608 1641 0x40 0x9
<7> [286.070676] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1440": 30 120850 2560 2608 2640 2720 1440 1443 1448 1481 0x40 0x9
<7> [286.070679] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1200": 60 154000 1920 1968 2000 2080 1200 1203 1209 1235 0x40 0x9
<7> [286.070682] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1080": 60 148352 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [286.070685] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1680x1050": 60 119000 1680 1728 1760 1840 1050 1053 1059 1080 0x40 0x9
<7> [286.070688] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1600x900": 60 108000 1600 1624 1704 1800 900 901 904 1000 0x40 0x5
<7> [286.070706] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x1024": 75 135000 1280 1296 1440 1688 1024 1025 1028 1066 0x40 0x5
<7> [286.070710] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x1024": 60 108000 1280 1328 1440 1688 1024 1025 1028 1066 0x40 0x5
<7> [286.070713] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1440x900": 60 88750 1440 1488 1520 1600 900 903 909 926 0x40 0x9
<7> [286.070716] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x800": 60 71000 1280 1328 1360 1440 800 803 809 823 0x40 0x9
<7> [286.070719] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1152x864": 75 108000 1152 1216 1344 1600 864 865 868 900 0x40 0x5
<7> [286.070722] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [286.070726] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74176 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [286.070742] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 75 78750 1024 1040 1136 1312 768 769 772 800 0x40 0x5
<7> [286.070745] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 70 75000 1024 1048 1184 1328 768 771 777 806 0x40 0xa
<7> [286.070748] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 60 65000 1024 1048 1184 1344 768 771 777 806 0x40 0xa
<7> [286.070751] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 75 49500 800 816 896 1056 600 601 604 625 0x40 0x5
<7> [286.070754] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 72 50000 800 856 976 1040 600 637 643 666 0x40 0x5
<7> [286.070757] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 60 40000 800 840 968 1056 600 601 605 628 0x40 0x5
<7> [286.070760] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 56 36000 800 824 896 1024 600 601 603 625 0x40 0x5
<7> [286.070764] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 75 31500 640 656 720 840 480 481 484 500 0x40 0xa
<7> [286.070767] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 73 31500 640 664 704 832 480 489 492 520 0x40 0xa
<7> [286.070770] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25200 640 656 752 800 480 490 492 525 0x40 0xa
<7> [286.070773] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa
<6> [286.071654] [IGT] kms_flip: starting subtest plain-flip-ts-check
<6> [286.077977] [IGT] kms_flip: starting dynamic subtest A-HDMI-A3
<7> [286.078437] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:561]
<7> [286.078574] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:563]
<7> [286.078903] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [286.079393] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [286.109406] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling AUX_D
<7> [286.137492] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [286.137855] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [286.143476] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [286.143841] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [286.165134] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [286.165553] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [286.192307] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [286.192431] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [286.192670] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [286.192880] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [286.193089] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [286.193311] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [286.193561] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [286.193769] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [286.193976] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [286.194183] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [286.194397] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [286.194602] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [286.194808] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [286.195015] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [286.195224] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [286.195475] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [286.195681] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [286.195887] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [286.196093] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [286.196310] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [286.196558] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [286.196764] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [286.196971] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [286.197177] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [286.197391] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [286.197598] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [286.197803] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [286.198011] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [286.198219] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [286.198435] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [286.198681] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [286.198888] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [286.199094] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [286.199306] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [286.199555] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [286.199763] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [286.199969] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [286.200174] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [286.200421] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [286.200653] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [286.200850] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [286.201077] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 1963) -> ( 0 - 0), size 1963 -> 0
<7> [286.201277] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [286.201512] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [286.201707] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [286.201902] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [286.202097] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 19, 55, 73, 91, 161, 196, 302, 443, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [286.202351] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 0 num active planes 0
<7> [286.202559] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 0
<7> [286.202782] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 74250 kHz -> 0 kHz
<7> [286.203005] i915 0000:03:00.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 9282 kHz -> 0 kHz
<7> [286.203211] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [286.203456] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [286.203664] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: no [modeset]
<7> [286.203871] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [286.204078] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [286.204284] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [286.204531] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [286.204736] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [286.204941] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [286.211969] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [286.229612] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [286.229920] i915 0000:03:00.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:35:plane 1A]
<7> [286.230150] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [286.230372] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [286.230644] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [286.230847] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [286.231049] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [286.231249] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [286.231493] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [286.231693] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [286.231894] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [286.232094] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [286.232323] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [286.232542] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [286.232742] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [286.232943] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [286.233143] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [286.233383] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [286.233606] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [286.233809] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [286.234010] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [286.234211] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [286.234450] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [286.234693] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [286.235007] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_A
<7> [286.235284] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [286.235582] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<7> [286.235999] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [286.236166] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [286.236342] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]
<7> [286.236511] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [286.236543] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:556:HDMI-A-3]
<7> [286.236617] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CONNECTOR:556:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [286.236842] i915 0000:03:00.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [286.237031] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [286.237240] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:547:DDI D/PHY D] [CRTC:151:pipe A]
<7> [286.237475] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [286.237682] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [286.237890] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [286.238100] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [286.238338] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [286.238560] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [286.238766] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [286.238973] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [286.239180] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [286.239392] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [286.239600] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [286.239808] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [286.240015] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [286.240221] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [286.240468] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [286.240675] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [286.240882] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [286.241089] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [286.241322] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [286.241542] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [286.241749] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [286.241955] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [286.242162] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [286.242451] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [286.242659] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [286.242866] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [286.243074] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [286.243280] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [286.243525] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [286.243733] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [286.243941] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [286.244149] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [286.244422] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [286.244629] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [286.244836] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [286.245043] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [286.245249] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [286.245494] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [286.245730] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [286.245927] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x1
<7> [286.246148] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [286.246382] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [286.246579] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [286.246775] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [286.246973] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0
<7> [286.247169] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0
<7> [286.247423] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 594000 num active planes 1
<7> [286.247630] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [286.247834] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [286.248054] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 74250 kHz
<7> [286.248273] i915 0000:03:00.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 9282 kHz
<7> [286.248518] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [286.248724] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [286.248930] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [286.249135] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [286.249380] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [286.249584] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [286.249788] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [286.249994] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [286.250200] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [286.250446] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [286.250652] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [286.250856] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [286.251063] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 41, vsync end: 36
<7> [286.251269] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125
<7> [286.251515] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [286.251721] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [286.251928] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [286.252134] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [286.252382] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [286.252589] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [286.252795] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pixel rate 148500, min cdclk 74250, min voltage level 0
<7> [286.253001] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [286.253207] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [286.253452] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [286.253658] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [286.253864] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [286.254068] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [286.254273] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [286.254521] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x40000000 gamma_enable: 0 csc_enable: 0
<7> [286.254597] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [286.254760] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 256 entries
<7> [286.254864] i915 0000:03:00.0: [drm:gen9_enable_dc5 [i915]] Enabling DC5
<7> [286.254965] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [286.255077] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 01
<7> [286.255170] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [286.255591] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [286.255796] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [286.256003] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [286.256208] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [286.256448] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [286.256654] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [286.256858] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [286.257063] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [286.257270] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:561] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [286.257515] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [286.257721] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [286.257927] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [286.258133] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [286.258380] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [286.258585] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [286.258791] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [286.259438] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [286.259771] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 01 to 00
<7> [286.260166] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [286.260465] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [286.260696] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [286.260899] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [286.261100] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [286.261330] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [286.261576] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [286.261777] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [286.261979] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [286.262180] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [286.262415] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [286.262616] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [286.262817] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [286.263018] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [286.263219] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [286.263455] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [286.263656] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [286.263855] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [286.264055] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [286.264255] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [286.264493] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [286.264694] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [286.264894] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [286.265342] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [286.265814] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [286.268366] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [286.268579] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]
<7> [286.284932] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [286.285264] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<7> [296.896295] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [296.896506] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [296.896987] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [296.897440] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [296.897875] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [296.898291] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [296.898762] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [296.899242] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [296.899731] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [296.900212] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [296.900707] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [296.901187] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [296.901670] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [296.901940] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [296.902177] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [296.902379] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [296.902628] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [296.902881] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [296.903112] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [296.903344] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [296.903546] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [296.903784] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [296.904001] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [296.904217] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [296.904433] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [296.904656] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [296.904873] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [296.905090] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [296.905308] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [296.905525] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [296.905746] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [296.905962] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [296.906178] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [296.906395] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [296.906613] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [296.906834] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [296.907052] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [296.907267] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [296.907485] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [296.907829] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [296.908040] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [296.908261] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 1963) -> ( 0 - 0), size 1963 -> 0
<7> [296.908470] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [296.908705] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [296.908901] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [296.909097] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [296.909293] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [296.909510] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 0 num active planes 0
<7> [296.909759] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 0
<7> [296.909979] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 74250 kHz -> 0 kHz
<7> [296.910200] i915 0000:03:00.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 9282 kHz -> 0 kHz
<7> [296.910406] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [296.910653] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [296.910861] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: no [modeset]
<7> [296.911068] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [296.911274] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [296.911479] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [296.911721] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [296.911925] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [296.912131] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [296.918371] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [296.935559] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [296.935889] i915 0000:03:00.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:35:plane 1A]
<7> [296.936138] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [296.936380] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [296.936627] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [296.936851] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [296.937071] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [296.937302] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [296.937524] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [296.937745] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [296.937965] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [296.938187] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [296.938416] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [296.938660] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [296.938899] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [296.939138] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [296.939382] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [296.939621] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [296.939884] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [296.940125] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [296.940376] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [296.940615] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [296.940854] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [296.941139] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [296.941503] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_A
<7> [296.941824] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [296.942116] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<7> [296.942634] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [296.942832] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [296.943006] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]
<7> [296.943191] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [296.943228] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:556:HDMI-A-3]
<7> [296.943316] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CONNECTOR:556:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [296.943582] i915 0000:03:00.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [296.943808] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [296.944056] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:547:DDI D/PHY D] [CRTC:151:pipe A]
<7> [296.944294] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [296.944545] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [296.944791] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [296.945037] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [296.945297] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [296.945543] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [296.945788] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [296.946035] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [296.946291] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [296.946538] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [296.946783] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [296.947028] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [296.947278] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [296.947523] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [296.947771] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [296.948017] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [296.948326] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [296.948572] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [296.948817] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [296.949062] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [296.949318] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [296.949565] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [296.949810] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [296.950056] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [296.950311] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [296.950556] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [296.950802] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [296.951049] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [296.951301] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [296.951546] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [296.951792] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [296.952039] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [296.952291] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [296.952539] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [296.952785] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [296.953031] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [296.953283] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [296.953529] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [296.953807] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [296.954050] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x1
<7> [296.954317] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [296.954549] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [296.954782] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [296.955015] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [296.955257] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0
<7> [296.955492] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0
<7> [296.955747] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 594000 num active planes 1
<7> [296.955992] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [296.956243] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [296.956503] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 74250 kHz
<7> [296.956763] i915 0000:03:00.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 9282 kHz
<7> [296.957015] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [296.957258] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [296.957503] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [296.957748] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [296.957999] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [296.958243] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [296.958488] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [296.958734] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [296.958986] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [296.959231] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [296.959476] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [296.959719] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [296.959975] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 41, vsync end: 36
<7> [296.960051] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [296.960222] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125
<7> [296.960343] i915 0000:03:00.0: [drm:gen9_enable_dc5 [i915]] Enabling DC5
<7> [296.960467] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [296.960596] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 01
<7> [296.960711] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [296.960966] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [296.961069] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling always-on
<7> [296.961212] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [296.961457] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [296.961702] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [296.961956] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pixel rate 148500, min cdclk 74250, min voltage level 0
<7> [296.962200] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [296.962444] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [296.962688] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [296.962939] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [296.963184] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [296.963429] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [296.963675] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [296.963895] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x40000000 gamma_enable: 0 csc_enable: 0
<7> [296.964124] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 256 entries
<7> [296.964345] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [296.964567] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [296.964789] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [296.965015] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [296.965234] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [296.965453] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [296.965674] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [296.965901] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [296.966121] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [296.966342] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [296.966563] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:561] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [296.966785] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [296.967014] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [296.967236] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [296.967456] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [296.967678] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [296.967906] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [296.968126] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [296.968428] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling always-on
<7> [296.968661] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [296.969040] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 01 to 00
<7> [296.969435] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [296.969694] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [296.969965] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [296.970167] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [296.970368] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [296.970569] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [296.970771] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [296.971012] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [296.971212] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [296.971414] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [296.971614] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [296.971820] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [296.972089] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [296.972290] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [296.972492] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [296.972692] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [296.972931] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [296.973132] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [296.973332] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [296.973533] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [296.973735] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [296.973975] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [296.974175] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [296.974589] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [296.975099] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [296.977420] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [296.977632] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]
<7> [296.994191] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [296.994524] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<6> [305.056332] [IGT] kms_flip: finished subtest A-HDMI-A3, FAIL
Created at 2026-04-06 10:50:14