Results for igt@kms_flip@wf_vblank-ts-check-interruptible@b-hdmi-a1

Result: Fail

integration-manifest git-log-oneline i915_display_info10 igt_runner10 runtimes10 results10.json results10-i915-load.json guc_logs10.tar i915_display_info_post_exec10 boot10 dmesg10

DetailValue
Duration 23.99 seconds
Hostname 
shard-rkl-5
Igt-Version 
IGT-Version: 2.3-g31b303e63 (x86_64) (Linux: 7.0.0-rc5-Patchwork_163782v1-g3a61374eb191+ x86_64)
Out 
Starting dynamic subtest: B-HDMI-A1
  1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 
Expected frametime: 18974us; measured 18972.9us +- 8.362us accuracy 0.13%
Event vblank: expected 536, counted 530, passrate = 35.85%, encoder type 2
Expected frametime: 18974us; measured 19134.6us +- 8.548us accuracy 0.13%
vblank interval differs from modeline! expected 18973.8us, measured 19135us +- 8.548us, difference 160.8us (18.8 sigma)
Event vblank: expected 527, counted 530, passrate = 69.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:2162 __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 B-HDMI-A1: FAIL (23.991s)
Err 
Starting dynamic subtest: B-HDMI-A1
(kms_flip:2488) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1711:
(kms_flip:2488) CRITICAL: Failed assertion: !retried
(kms_flip:2488) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-HDMI-A1 failed.
**** DEBUG ****
(kms_flip:2488) DEBUG: name = vblank
last_ts = 181.712845
last_received_ts = 181.712265
last_seq = 321
current_ts = 181.902588
current_received_ts = 181.901932
current_seq = 331
count = 14
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 181.712845/321, current 181.902588/331: elapsed=189737.0us expected=189729.4us +- 948.6us, error 0.0%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 181.902588
last_received_ts = 181.901932
last_seq = 331
current_ts = 182.092316
current_received_ts = 182.091660
current_seq = 341
count = 15
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 181.902588/331, current 182.092316/341: elapsed=189736.0us expected=189729.4us +- 948.6us, error 0.0%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 182.092316
last_received_ts = 182.091660
last_seq = 341
current_ts = 182.282104
current_received_ts = 182.281464
current_seq = 351
count = 16
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 182.092316/341, current 182.282104/351: elapsed=189783.0us expected=189729.4us +- 948.6us, error 0.0%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 182.282104
last_received_ts = 182.281464
last_seq = 351
current_ts = 182.471939
current_received_ts = 182.471344
current_seq = 361
count = 17
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 182.282104/351, current 182.471939/361: elapsed=189831.0us expected=189729.4us +- 948.6us, error 0.1%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 182.471939
last_received_ts = 182.471344
last_seq = 361
current_ts = 182.661758
current_received_ts = 182.661133
current_seq = 371
count = 18
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 182.471939/361, current 182.661758/371: elapsed=189824.0us expected=189729.4us +- 948.6us, error 0.0%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 182.661758
last_received_ts = 182.661133
last_seq = 371
current_ts = 182.854446
current_received_ts = 182.853836
current_seq = 381
count = 19
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 182.661758/371, current 182.854446/381: elapsed=192689.0us expected=189729.4us +- 948.6us, error 1.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 182.661758/371, current 182.854446/381: elapsed=192689.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 182.854446
last_received_ts = 182.853836
last_seq = 381
current_ts = 183.049316
current_received_ts = 183.048630
current_seq = 391
count = 20
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 182.854446/381, current 183.049316/391: elapsed=194869.0us expected=189729.4us +- 948.6us, error 2.7%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 182.854446/381, current 183.049316/391: elapsed=194869.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 183.049316
last_received_ts = 183.048630
last_seq = 391
current_ts = 183.244171
current_received_ts = 183.243500
current_seq = 401
count = 21
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 183.049316/391, current 183.244171/401: elapsed=194858.0us expected=189729.4us +- 948.6us, error 2.7%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 183.049316/391, current 183.244171/401: elapsed=194858.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 183.244171
last_received_ts = 183.243500
last_seq = 401
current_ts = 183.439041
current_received_ts = 183.438431
current_seq = 411
count = 22
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 183.244171/401, current 183.439041/411: elapsed=194866.0us expected=189729.4us +- 948.6us, error 2.7%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 183.244171/401, current 183.439041/411: elapsed=194866.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 183.439041
last_received_ts = 183.438431
last_seq = 411
current_ts = 183.633896
current_received_ts = 183.633270
current_seq = 421
count = 23
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 183.439041/411, current 183.633896/421: elapsed=194858.0us expected=189729.4us +- 948.6us, error 2.7%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 183.439041/411, current 183.633896/421: elapsed=194858.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 183.633896
last_received_ts = 183.633270
last_seq = 421
current_ts = 183.828476
current_received_ts = 183.827820
current_seq = 431
count = 24
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 183.633896/421, current 183.828476/431: elapsed=194574.0us expected=189729.4us +- 948.6us, error 2.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 183.633896/421, current 183.828476/431: elapsed=194574.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 183.828476
last_received_ts = 183.827820
last_seq = 431
current_ts = 184.022705
current_received_ts = 184.022095
current_seq = 441
count = 25
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 183.828476/431, current 184.022705/441: elapsed=194230.0us expected=189729.4us +- 948.6us, error 2.4%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 183.828476/431, current 184.022705/441: elapsed=194230.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 184.022705
last_received_ts = 184.022095
last_seq = 441
current_ts = 184.216949
current_received_ts = 184.216263
current_seq = 451
count = 26
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 184.022705/441, current 184.216949/451: elapsed=194243.0us expected=189729.4us +- 948.6us, error 2.4%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 184.022705/441, current 184.216949/451: elapsed=194243.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 184.216949
last_received_ts = 184.216263
last_seq = 451
current_ts = 184.411179
current_received_ts = 184.410553
current_seq = 461
count = 27
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 184.216949/451, current 184.411179/461: elapsed=194228.0us expected=189729.4us +- 948.6us, error 2.4%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 184.216949/451, current 184.411179/461: elapsed=194228.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 184.411179
last_received_ts = 184.410553
last_seq = 461
current_ts = 184.605408
current_received_ts = 184.604752
current_seq = 471
count = 28
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 184.411179/461, current 184.605408/471: elapsed=194237.0us expected=189729.4us +- 948.6us, error 2.4%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 184.411179/461, current 184.605408/471: elapsed=194237.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 184.605408
last_received_ts = 184.604752
last_seq = 471
current_ts = 184.799469
current_received_ts = 184.798828
current_seq = 481
count = 29
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 184.605408/471, current 184.799469/481: elapsed=194061.0us expected=189729.4us +- 948.6us, error 2.3%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 184.605408/471, current 184.799469/481: elapsed=194061.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 184.799469
last_received_ts = 184.798828
last_seq = 481
current_ts = 184.993164
current_received_ts = 184.992477
current_seq = 491
count = 30
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 184.799469/481, current 184.993164/491: elapsed=193686.0us expected=189729.4us +- 948.6us, error 2.1%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 184.799469/481, current 184.993164/491: elapsed=193686.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 184.993164
last_received_ts = 184.992477
last_seq = 491
current_ts = 185.186829
current_received_ts = 185.186218
current_seq = 501
count = 31
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 184.993164/491, current 185.186829/501: elapsed=193675.0us expected=189729.4us +- 948.6us, error 2.1%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 184.993164/491, current 185.186829/501: elapsed=193675.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 185.186829
last_received_ts = 185.186218
last_seq = 501
current_ts = 185.380524
current_received_ts = 185.379868
current_seq = 511
count = 32
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 185.186829/501, current 185.380524/511: elapsed=193683.0us expected=189729.4us +- 948.6us, error 2.1%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 185.186829/501, current 185.380524/511: elapsed=193683.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 185.380524
last_received_ts = 185.379868
last_seq = 511
current_ts = 185.574203
current_received_ts = 185.573532
current_seq = 521
count = 33
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 185.380524/511, current 185.574203/521: elapsed=193693.0us expected=189729.4us +- 948.6us, error 2.1%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 185.380524/511, current 185.574203/521: elapsed=193693.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 185.574203
last_received_ts = 185.573532
last_seq = 521
current_ts = 185.767822
current_received_ts = 185.767166
current_seq = 531
count = 34
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 185.574203/521, current 185.767822/531: elapsed=193619.0us expected=189729.4us +- 948.6us, error 2.1%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 185.574203/521, current 185.767822/531: elapsed=193619.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 185.767822
last_received_ts = 185.767166
last_seq = 531
current_ts = 185.961029
current_received_ts = 185.960342
current_seq = 541
count = 35
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 185.767822/531, current 185.961029/541: elapsed=193204.0us expected=189729.4us +- 948.6us, error 1.8%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 185.767822/531, current 185.961029/541: elapsed=193204.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 185.961029
last_received_ts = 185.960342
last_seq = 541
current_ts = 186.154221
current_received_ts = 186.153687
current_seq = 551
count = 36
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 185.961029/541, current 186.154221/551: elapsed=193194.0us expected=189729.4us +- 948.6us, error 1.8%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 185.961029/541, current 186.154221/551: elapsed=193194.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 186.154221
last_received_ts = 186.153687
last_seq = 551
current_ts = 186.347427
current_received_ts = 186.346771
current_seq = 561
count = 37
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 186.154221/551, current 186.347427/561: elapsed=193194.0us expected=189729.4us +- 948.6us, error 1.8%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 186.154221/551, current 186.347427/561: elapsed=193194.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 186.347427
last_received_ts = 186.346771
last_seq = 561
current_ts = 186.540634
current_received_ts = 186.540085
current_seq = 571
count = 38
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 186.347427/561, current 186.540634/571: elapsed=193211.0us expected=189729.4us +- 948.6us, error 1.8%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 186.347427/561, current 186.540634/571: elapsed=193211.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 186.540634
last_received_ts = 186.540085
last_seq = 571
current_ts = 186.733826
current_received_ts = 186.733170
current_seq = 581
count = 39
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 186.540634/571, current 186.733826/581: elapsed=193192.0us expected=189729.4us +- 948.6us, error 1.8%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 186.540634/571, current 186.733826/581: elapsed=193192.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 186.733826
last_received_ts = 186.733170
last_seq = 581
current_ts = 186.926620
current_received_ts = 186.926071
current_seq = 591
count = 40
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 186.733826/581, current 186.926620/591: elapsed=192800.0us expected=189729.4us +- 948.6us, error 1.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 186.733826/581, current 186.926620/591: elapsed=192800.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 186.926620
last_received_ts = 186.926071
last_seq = 591
current_ts = 187.119400
current_received_ts = 187.118759
current_seq = 601
count = 41
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 186.926620/591, current 187.119400/601: elapsed=192782.0us expected=189729.4us +- 948.6us, error 1.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 186.926620/591, current 187.119400/601: elapsed=192782.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 187.119400
last_received_ts = 187.118759
last_seq = 601
current_ts = 187.312180
current_received_ts = 187.311539
current_seq = 611
count = 42
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 187.119400/601, current 187.312180/611: elapsed=192777.0us expected=189729.4us +- 948.6us, error 1.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 187.119400/601, current 187.312180/611: elapsed=192777.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 187.312180
last_received_ts = 187.311539
last_seq = 611
current_ts = 187.504974
current_received_ts = 187.504333
current_seq = 621
count = 43
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 187.312180/611, current 187.504974/621: elapsed=192792.0us expected=189729.4us +- 948.6us, error 1.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 187.312180/611, current 187.504974/621: elapsed=192792.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 187.504974
last_received_ts = 187.504333
last_seq = 621
current_ts = 187.697754
current_received_ts = 187.697113
current_seq = 631
count = 44
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 187.504974/621, current 187.697754/631: elapsed=192781.0us expected=189729.4us +- 948.6us, error 1.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 187.504974/621, current 187.697754/631: elapsed=192781.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 187.697754
last_received_ts = 187.697113
last_seq = 631
current_ts = 187.890259
current_received_ts = 187.889771
current_seq = 641
count = 45
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 187.697754/631, current 187.890259/641: elapsed=192497.0us expected=189729.4us +- 948.6us, error 1.5%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 187.697754/631, current 187.890259/641: elapsed=192497.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 187.890259
last_received_ts = 187.889771
last_seq = 641
current_ts = 188.082657
current_received_ts = 188.082138
current_seq = 651
count = 46
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 187.890259/641, current 188.082657/651: elapsed=192406.0us expected=189729.4us +- 948.6us, error 1.4%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 187.890259/641, current 188.082657/651: elapsed=192406.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 188.082657
last_received_ts = 188.082138
last_seq = 651
current_ts = 188.275070
current_received_ts = 188.274445
current_seq = 661
count = 47
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 188.082657/651, current 188.275070/661: elapsed=192416.0us expected=189729.4us +- 948.6us, error 1.4%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 188.082657/651, current 188.275070/661: elapsed=192416.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 188.275070
last_received_ts = 188.274445
last_seq = 661
current_ts = 188.467468
current_received_ts = 188.466827
current_seq = 671
count = 48
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 188.275070/661, current 188.467468/671: elapsed=192399.0us expected=189729.4us +- 948.6us, error 1.4%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 188.275070/661, current 188.467468/671: elapsed=192399.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 188.467468
last_received_ts = 188.466827
last_seq = 671
current_ts = 188.659897
current_received_ts = 188.659210
current_seq = 681
count = 49
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 188.467468/671, current 188.659897/681: elapsed=192422.0us expected=189729.4us +- 948.6us, error 1.4%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 188.467468/671, current 188.659897/681: elapsed=192422.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 188.659897
last_received_ts = 188.659210
last_seq = 681
current_ts = 188.852112
current_received_ts = 188.851471
current_seq = 691
count = 50
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 188.659897/681, current 188.852112/691: elapsed=192216.0us expected=189729.4us +- 948.6us, error 1.3%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 188.659897/681, current 188.852112/691: elapsed=192216.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 188.852112
last_received_ts = 188.851471
last_seq = 691
current_ts = 189.044205
current_received_ts = 189.043564
current_seq = 701
count = 51
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 188.852112/691, current 189.044205/701: elapsed=192091.0us expected=189729.4us +- 948.6us, error 1.2%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 188.852112/691, current 189.044205/701: elapsed=192091.0us expected=189729.4us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 189.044205
last_received_ts = 189.043564
last_seq = 701
current_ts = 189.236298
current_received_ts = 189.235641
current_seq = 711
count = 52
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 189.044205/701, current 189.236298/711: elapsed=192088.0us expected=189729.4us +- 948.6us, error 1.2%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 189.044205/701, current 189.236298/711: elapsed=192088.0us expected=189729.4us
(kms_flip:2488) INFO: Event vblank: expected 536, counted 530, passrate = 35.85%, encoder type 2
(kms_flip:2488) DEBUG: dropped frames, expected 536, counted 530, passrate = 35.85%, encoder type 2
(kms_flip:2488) DEBUG: Retrying without a hotplug event
(kms_flip:2488) DEBUG: No stale events found
(kms_flip:2488) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2488) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2488) INFO: Expected frametime: 18974us; measured 19134.6us +- 8.548us accuracy 0.13%
(kms_flip:2488) INFO: vblank interval differs from modeline! expected 18973.8us, measured 19135us +- 8.548us, difference 160.8us (18.8 sigma)
(kms_flip:2488) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 192.852722
current_received_ts = 192.852203
current_seq = 742
count = 0
seq_step = 10
(kms_flip:2488) DEBUG: name = vblank
last_ts = 192.852722
last_received_ts = 192.852203
last_seq = 742
current_ts = 193.043884
current_received_ts = 193.043198
current_seq = 752
count = 1
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 192.852722/742, current 193.043884/752: elapsed=191163.0us expected=191345.6us +- 956.7us, error 0.1%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 193.043884
last_received_ts = 193.043198
last_seq = 752
current_ts = 193.235031
current_received_ts = 193.234344
current_seq = 762
count = 2
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 193.043884/752, current 193.235031/762: elapsed=191151.0us expected=191345.6us +- 956.7us, error 0.1%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 193.235031
last_received_ts = 193.234344
last_seq = 762
current_ts = 193.426193
current_received_ts = 193.425583
current_seq = 772
count = 3
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 193.235031/762, current 193.426193/772: elapsed=191157.0us expected=191345.6us +- 956.7us, error 0.1%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 193.426193
last_received_ts = 193.425583
last_seq = 772
current_ts = 193.617340
current_received_ts = 193.616699
current_seq = 782
count = 4
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 193.426193/772, current 193.617340/782: elapsed=191147.0us expected=191345.6us +- 956.7us, error 0.1%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 193.617340
last_received_ts = 193.616699
last_seq = 782
current_ts = 193.808441
current_received_ts = 193.807800
current_seq = 792
count = 5
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 193.617340/782, current 193.808441/792: elapsed=191099.0us expected=191345.6us +- 956.7us, error 0.1%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 193.808441
last_received_ts = 193.807800
last_seq = 792
current_ts = 193.999435
current_received_ts = 193.998856
current_seq = 802
count = 6
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 193.808441/792, current 193.999435/802: elapsed=190999.0us expected=191345.6us +- 956.7us, error 0.2%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 193.999435
last_received_ts = 193.998856
last_seq = 802
current_ts = 194.190414
current_received_ts = 194.189774
current_seq = 812
count = 7
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 193.999435/802, current 194.190414/812: elapsed=190981.0us expected=191345.6us +- 956.7us, error 0.2%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 194.190414
last_received_ts = 194.189774
last_seq = 812
current_ts = 194.381409
current_received_ts = 194.380798
current_seq = 822
count = 8
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 194.190414/812, current 194.381409/822: elapsed=190988.0us expected=191345.6us +- 956.7us, error 0.2%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 194.381409
last_received_ts = 194.380798
last_seq = 822
current_ts = 194.572403
current_received_ts = 194.571747
current_seq = 832
count = 9
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 194.381409/822, current 194.572403/832: elapsed=190992.0us expected=191345.6us +- 956.7us, error 0.2%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 194.572403
last_received_ts = 194.571747
last_seq = 832
current_ts = 194.763382
current_received_ts = 194.762695
current_seq = 842
count = 10
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 194.572403/832, current 194.763382/842: elapsed=190986.0us expected=191345.6us +- 956.7us, error 0.2%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 194.763382
last_received_ts = 194.762695
last_seq = 842
current_ts = 194.954224
current_received_ts = 194.953613
current_seq = 852
count = 11
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 194.763382/842, current 194.954224/852: elapsed=190847.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 194.954224
last_received_ts = 194.953613
last_seq = 852
current_ts = 195.145065
current_received_ts = 195.144501
current_seq = 862
count = 12
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 194.954224/852, current 195.145065/862: elapsed=190832.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 195.145065
last_received_ts = 195.144501
last_seq = 862
current_ts = 195.335922
current_received_ts = 195.335236
current_seq = 872
count = 13
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 195.145065/862, current 195.335922/872: elapsed=190856.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 195.335922
last_received_ts = 195.335236
last_seq = 872
current_ts = 195.526764
current_received_ts = 195.526123
current_seq = 882
count = 14
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 195.335922/872, current 195.526764/882: elapsed=190848.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 195.526764
last_received_ts = 195.526123
last_seq = 882
current_ts = 195.717606
current_received_ts = 195.717056
current_seq = 892
count = 15
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 195.526764/882, current 195.717606/892: elapsed=190841.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 195.717606
last_received_ts = 195.717056
last_seq = 892
current_ts = 195.908340
current_received_ts = 195.907684
current_seq = 902
count = 16
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 195.717606/892, current 195.908340/902: elapsed=190740.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 195.908340
last_received_ts = 195.907684
last_seq = 902
current_ts = 196.099060
current_received_ts = 196.098389
current_seq = 912
count = 17
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 195.908340/902, current 196.099060/912: elapsed=190714.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 196.099060
last_received_ts = 196.098389
last_seq = 912
current_ts = 196.289780
current_received_ts = 196.289139
current_seq = 922
count = 18
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 196.099060/912, current 196.289780/922: elapsed=190719.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 196.289780
last_received_ts = 196.289139
last_seq = 922
current_ts = 196.480484
current_received_ts = 196.479874
current_seq = 932
count = 19
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 196.289780/922, current 196.480484/932: elapsed=190709.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 196.480484
last_received_ts = 196.479874
last_seq = 932
current_ts = 196.671219
current_received_ts = 196.670609
current_seq = 942
count = 20
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 196.480484/932, current 196.671219/942: elapsed=190727.0us expected=191345.6us +- 956.7us, error 0.3%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 196.671219
last_received_ts = 196.670609
last_seq = 942
current_ts = 196.861877
current_received_ts = 196.861191
current_seq = 952
count = 21
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 196.671219/942, current 196.861877/952: elapsed=190653.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 196.861877
last_received_ts = 196.861191
last_seq = 952
current_ts = 197.052475
current_received_ts = 197.051788
current_seq = 962
count = 22
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 196.861877/952, current 197.052475/962: elapsed=190606.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 197.052475
last_received_ts = 197.051788
last_seq = 962
current_ts = 197.243088
current_received_ts = 197.242462
current_seq = 972
count = 23
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 197.052475/962, current 197.243088/972: elapsed=190611.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 197.243088
last_received_ts = 197.242462
last_seq = 972
current_ts = 197.433701
current_received_ts = 197.433044
current_seq = 982
count = 24
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 197.243088/972, current 197.433701/982: elapsed=190608.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 197.433701
last_received_ts = 197.433044
last_seq = 982
current_ts = 197.624283
current_received_ts = 197.623627
current_seq = 992
count = 25
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 197.433701/982, current 197.624283/992: elapsed=190592.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 197.624283
last_received_ts = 197.623627
last_seq = 992
current_ts = 197.814880
current_received_ts = 197.814255
current_seq = 1002
count = 26
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 197.624283/992, current 197.814880/1002: elapsed=190587.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 197.814880
last_received_ts = 197.814255
last_seq = 1002
current_ts = 198.005386
current_received_ts = 198.004913
current_seq = 1012
count = 27
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 197.814880/1002, current 198.005386/1012: elapsed=190505.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 198.005386
last_received_ts = 198.004913
last_seq = 1012
current_ts = 198.195892
current_received_ts = 198.195267
current_seq = 1022
count = 28
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 198.005386/1012, current 198.195892/1022: elapsed=190517.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 198.195892
last_received_ts = 198.195267
last_seq = 1022
current_ts = 198.386398
current_received_ts = 198.385803
current_seq = 1032
count = 29
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 198.195892/1022, current 198.386398/1032: elapsed=190498.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 198.386398
last_received_ts = 198.385803
last_seq = 1032
current_ts = 198.576904
current_received_ts = 198.576279
current_seq = 1042
count = 30
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 198.386398/1032, current 198.576904/1042: elapsed=190510.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 198.576904
last_received_ts = 198.576279
last_seq = 1042
current_ts = 198.767410
current_received_ts = 198.766754
current_seq = 1052
count = 31
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 198.576904/1042, current 198.767410/1052: elapsed=190501.0us expected=191345.6us +- 956.7us, error 0.4%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 198.767410
last_received_ts = 198.766754
last_seq = 1052
current_ts = 198.957825
current_received_ts = 198.957214
current_seq = 1062
count = 32
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 198.767410/1052, current 198.957825/1062: elapsed=190425.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 198.957825
last_received_ts = 198.957214
last_seq = 1062
current_ts = 199.148270
current_received_ts = 199.147675
current_seq = 1072
count = 33
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 198.957825/1062, current 199.148270/1072: elapsed=190437.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 199.148270
last_received_ts = 199.147675
last_seq = 1072
current_ts = 199.338684
current_received_ts = 199.338074
current_seq = 1082
count = 34
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 199.148270/1072, current 199.338684/1082: elapsed=190417.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 199.338684
last_received_ts = 199.338074
last_seq = 1082
current_ts = 199.529114
current_received_ts = 199.528473
current_seq = 1092
count = 35
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 199.338684/1082, current 199.529114/1092: elapsed=190430.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 199.529114
last_received_ts = 199.528473
last_seq = 1092
current_ts = 199.719543
current_received_ts = 199.718887
current_seq = 1102
count = 36
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 199.529114/1092, current 199.719543/1102: elapsed=190423.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: name = vblank
last_ts = 199.719543
last_received_ts = 199.718887
last_seq = 1102
current_ts = 199.909912
current_received_ts = 199.909225
current_seq = 1112
count = 37
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 199.719543/1102, current 199.909912/1112: elapsed=190372.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 199.719543/1102, current 199.909912/1112: elapsed=190372.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 199.909912
last_received_ts = 199.909225
last_seq = 1112
current_ts = 200.100250
current_received_ts = 200.099686
current_seq = 1122
count = 38
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 199.909912/1112, current 200.100250/1122: elapsed=190338.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 199.909912/1112, current 200.100250/1122: elapsed=190338.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 200.100250
last_received_ts = 200.099686
last_seq = 1122
current_ts = 200.290604
current_received_ts = 200.289948
current_seq = 1132
count = 39
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 200.100250/1122, current 200.290604/1132: elapsed=190355.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 200.100250/1122, current 200.290604/1132: elapsed=190355.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 200.290604
last_received_ts = 200.289948
last_seq = 1132
current_ts = 200.480972
current_received_ts = 200.480331
current_seq = 1142
count = 40
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 200.290604/1132, current 200.480972/1142: elapsed=190364.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 200.290604/1132, current 200.480972/1142: elapsed=190364.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 200.480972
last_received_ts = 200.480331
last_seq = 1142
current_ts = 200.671310
current_received_ts = 200.670761
current_seq = 1152
count = 41
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 200.480972/1142, current 200.671310/1152: elapsed=190347.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 200.480972/1142, current 200.671310/1152: elapsed=190347.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 200.671310
last_received_ts = 200.670761
last_seq = 1152
current_ts = 200.861618
current_received_ts = 200.861008
current_seq = 1162
count = 42
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 200.671310/1152, current 200.861618/1162: elapsed=190304.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 200.671310/1152, current 200.861618/1162: elapsed=190304.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 200.861618
last_received_ts = 200.861008
last_seq = 1162
current_ts = 201.051910
current_received_ts = 201.051239
current_seq = 1172
count = 43
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 200.861618/1162, current 201.051910/1172: elapsed=190298.0us expected=191345.6us +- 956.7us, error 0.5%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 200.861618/1162, current 201.051910/1172: elapsed=190298.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 201.051910
last_received_ts = 201.051239
last_seq = 1172
current_ts = 201.242203
current_received_ts = 201.241516
current_seq = 1182
count = 44
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 201.051910/1172, current 201.242203/1182: elapsed=190284.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 201.051910/1172, current 201.242203/1182: elapsed=190284.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 201.242203
last_received_ts = 201.241516
last_seq = 1182
current_ts = 201.432480
current_received_ts = 201.431824
current_seq = 1192
count = 45
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 201.242203/1182, current 201.432480/1192: elapsed=190278.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 201.242203/1182, current 201.432480/1192: elapsed=190278.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 201.432480
last_received_ts = 201.431824
last_seq = 1192
current_ts = 201.622772
current_received_ts = 201.622147
current_seq = 1202
count = 46
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 201.432480/1192, current 201.622772/1202: elapsed=190292.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 201.432480/1192, current 201.622772/1202: elapsed=190292.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 201.622772
last_received_ts = 201.622147
last_seq = 1202
current_ts = 201.813049
current_received_ts = 201.812408
current_seq = 1212
count = 47
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 201.622772/1202, current 201.813049/1212: elapsed=190274.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 201.622772/1202, current 201.813049/1212: elapsed=190274.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 201.813049
last_received_ts = 201.812408
last_seq = 1212
current_ts = 202.003265
current_received_ts = 202.002594
current_seq = 1222
count = 48
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 201.813049/1212, current 202.003265/1222: elapsed=190230.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 201.813049/1212, current 202.003265/1222: elapsed=190230.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 202.003265
last_received_ts = 202.002594
last_seq = 1222
current_ts = 202.193497
current_received_ts = 202.192841
current_seq = 1232
count = 49
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 202.003265/1222, current 202.193497/1232: elapsed=190219.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 202.003265/1222, current 202.193497/1232: elapsed=190219.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 202.193497
last_received_ts = 202.192841
last_seq = 1232
current_ts = 202.383728
current_received_ts = 202.383087
current_seq = 1242
count = 50
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 202.193497/1232, current 202.383728/1242: elapsed=190233.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 202.193497/1232, current 202.383728/1242: elapsed=190233.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 202.383728
last_received_ts = 202.383087
last_seq = 1242
current_ts = 202.573959
current_received_ts = 202.573334
current_seq = 1252
count = 51
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 202.383728/1242, current 202.573959/1252: elapsed=190240.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 202.383728/1242, current 202.573959/1252: elapsed=190240.0us expected=191345.6us
(kms_flip:2488) DEBUG: name = vblank
last_ts = 202.573959
last_received_ts = 202.573334
last_seq = 1252
current_ts = 202.764175
current_received_ts = 202.763535
current_seq = 1262
count = 52
seq_step = 10
(kms_flip:2488) DEBUG: vblank ts/seq: last 202.573959/1252, current 202.764175/1262: elapsed=190210.0us expected=191345.6us +- 956.7us, error 0.6%
(kms_flip:2488) DEBUG: inconsistent vblank ts/seq: last 202.573959/1252, current 202.764175/1262: elapsed=190210.0us expected=191345.6us
(kms_flip:2488) INFO: Event vblank: expected 527, counted 530, passrate = 69.81%, encoder type 2
(kms_flip:2488) DEBUG: dropped frames, expected 527, counted 530, passrate = 69.81%, encoder type 2
(kms_flip:2488) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1711:
(kms_flip:2488) CRITICAL: Failed assertion: !retried
(kms_flip:2488) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2488) igt_core-INFO: Stack trace:
(kms_flip:2488) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2488) igt_core-INFO:   #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
(kms_flip:2488) igt_core-INFO:   #2 ../tests/kms_flip.c:1891 run_test()
(kms_flip:2488) igt_core-INFO:   #3 ../tests/kms_flip.c:2162 __igt_unique____real_main2047()
(kms_flip:2488) igt_core-INFO:   #4 ../tests/kms_flip.c:2047 main()
(kms_flip:2488) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2488) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2488) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-HDMI-A1: FAIL (23.991s)
Dmesg
<6> [192.972091] [IGT] kms_flip: starting dynamic subtest B-HDMI-A1
<7> [192.973449] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:418]
<7> [192.973999] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:419]
<7> [192.985867] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [192.986057] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [192.986195] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02
<7> [192.992761] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [192.992850] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [192.992994] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [192.993128] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [192.993269] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [192.993453] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [192.993638] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [192.993802] i915 0000:00:02.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> [192.993932] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0)
<7> [192.994062] i915 0000:00:02.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> [192.994191] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0)
<7> [192.994376] i915 0000:00:02.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> [192.994564] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0)
<7> [192.994750] i915 0000:00:02.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> [192.994886] i915 0000:00:02.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> [192.995015] i915 0000:00:02.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> [192.995143] i915 0000:00:02.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> [192.995272] i915 0000:00:02.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> [192.995443] i915 0000:00:02.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> [192.995633] i915 0000:00:02.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> [192.995848] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0)
<7> [192.995981] i915 0000:00:02.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> [192.996111] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0)
<7> [192.996242] i915 0000:00:02.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> [192.996377] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0)
<7> [192.996568] i915 0000:00:02.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> [192.996764] i915 0000:00:02.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> [192.996906] i915 0000:00:02.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> [192.997034] i915 0000:00:02.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> [192.997164] i915 0000:00:02.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> [192.997292] i915 0000:00:02.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> [192.997457] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [192.997645] i915 0000:00:02.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> [192.997841] i915 0000:00:02.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> [192.997975] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [192.998108] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0)
<7> [192.998239] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0)
<7> [192.998383] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 139929, found 0)
<7> [192.998576] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [192.998764] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:151:pipe A] releasing DPLL 0
<7> [192.998917] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no
<7> [192.999049] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [192.999200] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0
<7> [192.999364] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 69965 kHz -> 0 kHz
<7> [192.999567] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: no [modeset]
<7> [192.999745] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [192.999877] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [193.000008] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [193.000140] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [193.000287] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [193.000482] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [193.000736] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [193.000935] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 02 to 00
<7> [193.001478] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [193.007819] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B
<7> [193.008079] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Disabling DP dual mode adaptor TMDS output
<7> [193.012955] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]
<7> [193.013113] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [193.013260] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [193.013407] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [193.013542] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [193.013673] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [193.013820] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [193.013950] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [193.014080] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:390:HDMI-A-1]
<7> [193.014272] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [193.014457] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<7> [193.014758] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [193.014858] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [193.014943] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [193.014963] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:390:HDMI-A-1]
<7> [193.015019] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:390:HDMI-A-1] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)
<7> [193.015162] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [193.015288] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:269:pipe B] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [193.015423] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:389:DDI B/PHY B] [CRTC:269:pipe B]
<7> [193.015555] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.enable (expected no, found yes)
<7> [193.015689] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.active (expected no, found yes)
<7> [193.015839] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)
<7> [193.015970] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in lane_count (expected 0, found 4)
<7> [193.016101] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [193.016231] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [193.016361] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [193.016491] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360)
<7> [193.016620] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [193.016805] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360)
<7> [193.016964] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [193.017093] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096)
<7> [193.017222] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [193.017351] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [193.017480] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [193.017609] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [193.017736] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [193.017882] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [193.018011] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [193.018138] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360)
<7> [193.018266] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [193.018394] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360)
<7> [193.018522] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [193.018650] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096)
<7> [193.018789] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [193.018916] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [193.019044] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [193.019172] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [193.019300] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [193.019428] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [193.019555] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [193.019684] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [193.019822] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [193.019950] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [193.020078] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929)
<7> [193.020205] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929)
<7> [193.020333] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in port_clock (expected 0, found 139929)
<7> [193.020461] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:269:pipe B] fastset requirement not met, forcing full modeset
<7> [193.020609] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no
<7> [193.020748] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:269:pipe B] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x2
<7> [193.020900] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:153:plane 1B] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016
<7> [193.021028] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:263:cursor B] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32
<7> [193.021156] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [193.021284] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0
<7> [193.021411] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0
<7> [193.021538] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0
<7> [193.021678] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:269:pipe B] data rate 559716 num active planes 1
<7> [193.021825] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560
<7> [193.021958] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [193.022100] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:269:pipe B] min cdclk: 0 kHz -> 69965 kHz
<7> [193.022246] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:269:pipe B] allocated DPLL 0
<7> [193.022382] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:269:pipe B] reserving DPLL 0
<7> [193.022518] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:269:pipe B] enable: yes [modeset]
<7> [193.022650] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [193.022792] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 24, dithering: 0
<7> [193.022923] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [193.023053] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [193.023183] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [193.023313] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [193.023442] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [193.023572] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [193.023700] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [193.023837] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0
<7> [193.023966] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125
<7> [193.024096] i915 0000:00:02.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> [193.024225] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [193.024354] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [193.024483] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [193.024612] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5
<7> [193.024747] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [193.024877] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pipe src: 1920x1080+0+0, pixel rate 139929, min cdclk 69965
<7> [193.025005] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0
<7> [193.025133] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [193.025260] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [193.025389] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [193.025517] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0
<7> [193.025645] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [193.025797] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [193.025925] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [193.026052] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [193.026179] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [193.026308] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [193.026435] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [193.026562] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [193.026691] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [193.026829] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [193.026957] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [193.027085] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [193.027213] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [193.027340] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 1B] fb: [FB:418] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [193.027468] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [193.027595] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [193.027723] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:183:plane 2B] fb: [NOFB], visible: no
<7> [193.027864] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:213:plane 3B] fb: [NOFB], visible: no
<7> [193.027991] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:243:plane 4B] fb: [NOFB], visible: no
<7> [193.028118] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:253:plane 5B] fb: [NOFB], visible: no
<7> [193.028245] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:263:cursor B] fb: [NOFB], visible: no
<7> [193.028901] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3
<7> [193.029069] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [193.029207] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [193.029341] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [193.029475] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [193.029606] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [193.029736] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [193.029945] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [193.030110] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x2, on? 0) for [CRTC:269:pipe B]
<7> [193.030246] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [193.030422] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Enabling DP dual mode adaptor TMDS output
<7> [193.035247] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B
<7> [193.035417] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe B
<7> [193.055394] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:390:HDMI-A-1]
<7> [193.055662] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:269:pipe B]
<6> [195.625370] pcieport 0000:00:06.0: AER: Correctable error message received from 0000:01:00.0
<4> [195.625387] nvme 0000:01:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
<4> [195.625394] nvme 0000:01:00.0: device [15b7:5006] error status/mask=00000001/0000e000
<4> [195.625401] nvme 0000:01:00.0: [ 0] RxErr (First)
<7> [206.427161] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [206.427942] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [206.428195] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [206.428978] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [206.429713] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [206.430344] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [206.431023] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [206.431713] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [206.432326] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [206.432549] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0)
<7> [206.432689] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [206.432819] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0)
<7> [206.432949] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [206.433079] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0)
<7> [206.433206] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [206.433336] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [206.433477] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [206.433617] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [206.433746] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [206.433874] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [206.434002] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [206.434130] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0)
<7> [206.434258] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [206.434387] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0)
<7> [206.434529] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [206.434669] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0)
<7> [206.434798] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [206.434926] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [206.435054] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [206.435183] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [206.435311] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [206.435439] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [206.435584] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [206.435723] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [206.435851] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [206.435980] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [206.436109] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0)
<7> [206.436237] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0)
<7> [206.436365] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in port_clock (expected 139929, found 0)
<7> [206.436506] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:269:pipe B] fastset requirement not met, forcing full modeset
<7> [206.436646] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:269:pipe B] releasing DPLL 0
<7> [206.436795] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no
<7> [206.436926] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:269:pipe B] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [206.437074] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:153:plane 1B] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0
<7> [206.437201] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:263:cursor B] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0
<7> [206.437329] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [206.437467] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [206.437610] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [206.437740] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] min_ddb 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [206.437882] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:269:pipe B] data rate 0 num active planes 0
<7> [206.438017] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0
<7> [206.438149] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [206.438294] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:269:pipe B] min cdclk: 69965 kHz -> 0 kHz
<7> [206.438475] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 8746 kHz -> 0 kHz
<7> [206.438609] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:269:pipe B] enable: no [modeset]
<7> [206.438743] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 1B] fb: [NOFB], visible: no
<7> [206.438875] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:183:plane 2B] fb: [NOFB], visible: no
<7> [206.439006] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:213:plane 3B] fb: [NOFB], visible: no
<7> [206.439138] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:243:plane 4B] fb: [NOFB], visible: no
<7> [206.439268] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:253:plane 5B] fb: [NOFB], visible: no
<7> [206.439400] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:263:cursor B] fb: [NOFB], visible: no
<7> [206.439646] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B
<7> [206.452463] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B
<7> [206.452692] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Disabling DP dual mode adaptor TMDS output
<7> [206.457632] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:269:pipe B]
<7> [206.457849] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [206.458050] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [206.458265] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [206.458464] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [206.458649] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [206.458877] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [206.459109] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [206.459365] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:390:HDMI-A-1]
<7> [206.459725] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [206.459999] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3
<7> [206.460211] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:269:pipe B]
<7> [206.460676] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [206.460838] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [206.460865] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:390:HDMI-A-1]
<7> [206.460932] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:390:HDMI-A-1] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)
<7> [206.461111] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [206.461289] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:269:pipe B] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [206.461471] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:389:DDI B/PHY B] [CRTC:269:pipe B]
<7> [206.461642] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.enable (expected no, found yes)
<7> [206.461858] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.active (expected no, found yes)
<7> [206.462025] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)
<7> [206.462203] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in lane_count (expected 0, found 4)
<7> [206.462395] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [206.462588] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [206.462766] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [206.462932] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360)
<7> [206.463075] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [206.463207] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360)
<7> [206.463359] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [206.463502] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096)
<7> [206.463670] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [206.463801] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [206.463931] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [206.464060] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [206.464190] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [206.464337] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [206.464477] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [206.464605] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360)
<7> [206.464734] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [206.464862] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360)
<7> [206.464996] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [206.465124] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096)
<7> [206.465276] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [206.465414] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [206.465542] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [206.465702] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [206.465830] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [206.465965] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [206.466093] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [206.466246] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [206.466381] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [206.466537] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [206.466665] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929)
<7> [206.466800] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929)
<7> [206.466928] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in port_clock (expected 0, found 139929)
<7> [206.467064] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:269:pipe B] fastset requirement not met, forcing full modeset
<7> [206.467235] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no
<7> [206.467391] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:269:pipe B] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x2
<7> [206.467548] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:153:plane 1B] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016
<7> [206.467684] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:263:cursor B] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32
<7> [206.467811] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [206.467948] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0
<7> [206.468078] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0
<7> [206.468260] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:153:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0
<7> [206.468417] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:269:pipe B] data rate 559716 num active planes 1
<7> [206.468554] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560
<7> [206.468691] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [206.468835] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:269:pipe B] min cdclk: 0 kHz -> 69965 kHz
<7> [206.469005] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 8746 kHz
<7> [206.469137] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:269:pipe B] allocated DPLL 0
<7> [206.469296] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:269:pipe B] reserving DPLL 0
<7> [206.469441] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:269:pipe B] enable: yes [modeset]
<7> [206.469581] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [206.469713] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 24, dithering: 0
<7> [206.469875] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [206.470005] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [206.470142] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [206.470290] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [206.470436] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [206.470568] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [206.470699] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [206.470830] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0
<7> [206.470960] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125
<7> [206.471089] i915 0000:00:02.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> [206.471232] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [206.471372] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [206.471501] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [206.471631] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5
<7> [206.471759] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [206.471888] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pipe src: 1920x1080+0+0, pixel rate 139929, min cdclk 69965
<7> [206.472016] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0
<7> [206.472153] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [206.472292] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [206.472420] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [206.472547] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0
<7> [206.472675] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [206.472802] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [206.472929] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [206.473057] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [206.473250] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [206.473377] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [206.473504] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [206.473631] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [206.473759] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [206.473886] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [206.474013] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [206.474155] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [206.474296] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [206.474423] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 1B] fb: [FB:418] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [206.474551] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [206.474678] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [206.474806] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:183:plane 2B] fb: [NOFB], visible: no
<7> [206.474933] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:213:plane 3B] fb: [NOFB], visible: no
<7> [206.475060] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:243:plane 4B] fb: [NOFB], visible: no
<7> [206.475201] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:253:plane 5B] fb: [NOFB], visible: no
<7> [206.475340] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:263:cursor B] fb: [NOFB], visible: no
<7> [206.475531] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3
<7> [206.475687] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [206.475821] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [206.475953] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [206.476084] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [206.476233] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [206.476375] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [206.476540] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [206.476705] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x2, on? 0) for [CRTC:269:pipe B]
<7> [206.476839] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [206.477367] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Enabling DP dual mode adaptor TMDS output
<7> [206.482285] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B
<7> [206.482461] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe B
<7> [206.502535] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:390:HDMI-A-1]
<7> [206.502799] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:269:pipe B]
<6> [216.962826] [IGT] kms_flip: finished subtest B-HDMI-A1, FAIL
Created at 2026-03-25 01:01:53