Results for igt@kms_flip@wf_vblank-ts-check-interruptible@c-hdmi-a2

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.80 seconds
Hostname
shard-rkl-4
Igt-Version
IGT-Version: 2.4-ga5c5d6558 (x86_64) (Linux: 7.1.0-rc1-CI_DRM_18369-gb6f6b69b2dff+ x86_64)
Out
Starting dynamic subtest: C-HDMI-A2
  1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 
Expected frametime: 18974us; measured 18974.2us +- 5.180us accuracy 0.08%
Event vblank: expected 527, counted 520, passrate = 28.85%, encoder type 2
Expected frametime: 18974us; measured 19134.2us +- 6.047us accuracy 0.09%
vblank interval differs from modeline! expected 18973.8us, measured 19134us +- 6.047us, difference 160.4us (26.5 sigma)
Event vblank: expected 528, counted 530, passrate = 73.58%, encoder type 2
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:1071 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest C-HDMI-A2: FAIL (23.804s)
Subtest wf_vblank-ts-check-interruptible: FAIL (44.842s)
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2352 kmstest_set_connector_dpms()
  #2 ../lib/igt_core.c:2961 igt_atexit_handler()
  #3 [erand48_r+0x1d6]
  #4 [exit+0x1e]
  #5 ../lib/igt_core.c:2416 igt_exit()
  #6 [main+0x3f]
  #7 [__libc_init_first+0x8a]
  #8 [__libc_start_main+0x8b]
  #9 [_start+0x25]
Err
Starting dynamic subtest: C-HDMI-A2
(kms_flip:2349) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1722:
(kms_flip:2349) CRITICAL: Failed assertion: !retried
(kms_flip:2349) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest C-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2349) DEBUG: vblank ts/seq: last 211.781509/516, current 211.971252/526: elapsed=189739.0us expected=189741.9us +- 948.7us, error 0.0%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 211.971252
last_received_ts = 211.970734
last_seq = 526
current_ts = 212.161026
current_received_ts = 212.160400
current_seq = 536
count = 14
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 211.971252/526, current 212.161026/536: elapsed=189774.0us expected=189741.9us +- 948.7us, error 0.0%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 212.161026
last_received_ts = 212.160400
last_seq = 536
current_ts = 212.355118
current_received_ts = 212.354492
current_seq = 546
count = 15
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 212.161026/536, current 212.355118/546: elapsed=194093.0us expected=189741.9us +- 948.7us, error 2.3%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 212.161026/536, current 212.355118/546: elapsed=194093.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 212.355118
last_received_ts = 212.354492
last_seq = 546
current_ts = 212.550690
current_received_ts = 212.550095
current_seq = 556
count = 16
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 212.355118/546, current 212.550690/556: elapsed=195579.0us expected=189741.9us +- 948.7us, error 3.1%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 212.355118/546, current 212.550690/556: elapsed=195579.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 212.550690
last_received_ts = 212.550095
last_seq = 556
current_ts = 212.746262
current_received_ts = 212.745728
current_seq = 566
count = 17
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 212.550690/556, current 212.746262/566: elapsed=195572.0us expected=189741.9us +- 948.7us, error 3.1%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 212.550690/556, current 212.746262/566: elapsed=195572.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 212.746262
last_received_ts = 212.745728
last_seq = 566
current_ts = 212.941833
current_received_ts = 212.941162
current_seq = 576
count = 18
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 212.746262/566, current 212.941833/576: elapsed=195572.0us expected=189741.9us +- 948.7us, error 3.1%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 212.746262/566, current 212.941833/576: elapsed=195572.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 212.941833
last_received_ts = 212.941162
last_seq = 576
current_ts = 213.137405
current_received_ts = 213.136658
current_seq = 586
count = 19
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 212.941833/576, current 213.137405/586: elapsed=195566.0us expected=189741.9us +- 948.7us, error 3.1%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 212.941833/576, current 213.137405/586: elapsed=195566.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 213.137405
last_received_ts = 213.136658
last_seq = 586
current_ts = 213.332520
current_received_ts = 213.331955
current_seq = 596
count = 20
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 213.137405/586, current 213.332520/596: elapsed=195122.0us expected=189741.9us +- 948.7us, error 2.8%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 213.137405/586, current 213.332520/596: elapsed=195122.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 213.332520
last_received_ts = 213.331955
last_seq = 596
current_ts = 213.527374
current_received_ts = 213.526810
current_seq = 606
count = 21
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 213.332520/596, current 213.527374/606: elapsed=194852.0us expected=189741.9us +- 948.7us, error 2.7%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 213.332520/596, current 213.527374/606: elapsed=194852.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 213.527374
last_received_ts = 213.526810
last_seq = 606
current_ts = 213.722229
current_received_ts = 213.721664
current_seq = 616
count = 22
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 213.527374/606, current 213.722229/616: elapsed=194850.0us expected=189741.9us +- 948.7us, error 2.7%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 213.527374/606, current 213.722229/616: elapsed=194850.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 213.722229
last_received_ts = 213.721664
last_seq = 616
current_ts = 213.917084
current_received_ts = 213.916519
current_seq = 626
count = 23
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 213.722229/616, current 213.917084/626: elapsed=194849.0us expected=189741.9us +- 948.7us, error 2.7%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 213.722229/616, current 213.917084/626: elapsed=194849.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 213.917084
last_received_ts = 213.916519
last_seq = 626
current_ts = 214.111938
current_received_ts = 214.111313
current_seq = 636
count = 24
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 213.917084/626, current 214.111938/636: elapsed=194855.0us expected=189741.9us +- 948.7us, error 2.7%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 213.917084/626, current 214.111938/636: elapsed=194855.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 214.111938
last_received_ts = 214.111313
last_seq = 636
current_ts = 214.306473
current_received_ts = 214.305878
current_seq = 646
count = 25
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 214.111938/636, current 214.306473/646: elapsed=194541.0us expected=189741.9us +- 948.7us, error 2.5%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 214.111938/636, current 214.306473/646: elapsed=194541.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 214.306473
last_received_ts = 214.305878
last_seq = 646
current_ts = 214.500702
current_received_ts = 214.500076
current_seq = 656
count = 26
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 214.306473/646, current 214.500702/656: elapsed=194228.0us expected=189741.9us +- 948.7us, error 2.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 214.306473/646, current 214.500702/656: elapsed=194228.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 214.500702
last_received_ts = 214.500076
last_seq = 656
current_ts = 214.694916
current_received_ts = 214.694305
current_seq = 666
count = 27
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 214.500702/656, current 214.694916/666: elapsed=194221.0us expected=189741.9us +- 948.7us, error 2.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 214.500702/656, current 214.694916/666: elapsed=194221.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 214.694916
last_received_ts = 214.694305
last_seq = 666
current_ts = 214.889145
current_received_ts = 214.888504
current_seq = 676
count = 28
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 214.694916/666, current 214.889145/676: elapsed=194226.0us expected=189741.9us +- 948.7us, error 2.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 214.694916/666, current 214.889145/676: elapsed=194226.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 214.889145
last_received_ts = 214.888504
last_seq = 676
current_ts = 215.083359
current_received_ts = 215.082733
current_seq = 686
count = 29
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 214.889145/676, current 215.083359/686: elapsed=194218.0us expected=189741.9us +- 948.7us, error 2.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 214.889145/676, current 215.083359/686: elapsed=194218.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 215.083359
last_received_ts = 215.082733
last_seq = 686
current_ts = 215.277405
current_received_ts = 215.276749
current_seq = 696
count = 30
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 215.083359/686, current 215.277405/696: elapsed=194032.0us expected=189741.9us +- 948.7us, error 2.3%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 215.083359/686, current 215.277405/696: elapsed=194032.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 215.277405
last_received_ts = 215.276749
last_seq = 696
current_ts = 215.471069
current_received_ts = 215.470413
current_seq = 706
count = 31
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 215.277405/696, current 215.471069/706: elapsed=193671.0us expected=189741.9us +- 948.7us, error 2.1%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 215.277405/696, current 215.471069/706: elapsed=193671.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 215.471069
last_received_ts = 215.470413
last_seq = 706
current_ts = 215.664749
current_received_ts = 215.664108
current_seq = 716
count = 32
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 215.471069/706, current 215.664749/716: elapsed=193677.0us expected=189741.9us +- 948.7us, error 2.1%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 215.471069/706, current 215.664749/716: elapsed=193677.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 215.664749
last_received_ts = 215.664108
last_seq = 716
current_ts = 215.858429
current_received_ts = 215.857864
current_seq = 726
count = 33
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 215.664749/716, current 215.858429/726: elapsed=193684.0us expected=189741.9us +- 948.7us, error 2.1%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 215.664749/716, current 215.858429/726: elapsed=193684.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 215.858429
last_received_ts = 215.857864
last_seq = 726
current_ts = 216.052109
current_received_ts = 216.051498
current_seq = 736
count = 34
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 215.858429/726, current 216.052109/736: elapsed=193680.0us expected=189741.9us +- 948.7us, error 2.1%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 215.858429/726, current 216.052109/736: elapsed=193680.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 216.052109
last_received_ts = 216.051498
last_seq = 736
current_ts = 216.245697
current_received_ts = 216.245102
current_seq = 746
count = 35
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 216.052109/736, current 216.245697/746: elapsed=193581.0us expected=189741.9us +- 948.7us, error 2.0%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 216.052109/736, current 216.245697/746: elapsed=193581.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 216.245697
last_received_ts = 216.245102
last_seq = 746
current_ts = 216.438889
current_received_ts = 216.438309
current_seq = 756
count = 36
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 216.245697/746, current 216.438889/756: elapsed=193198.0us expected=189741.9us +- 948.7us, error 1.8%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 216.245697/746, current 216.438889/756: elapsed=193198.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 216.438889
last_received_ts = 216.438309
last_seq = 756
current_ts = 216.632080
current_received_ts = 216.631470
current_seq = 766
count = 37
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 216.438889/756, current 216.632080/766: elapsed=193192.0us expected=189741.9us +- 948.7us, error 1.8%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 216.438889/756, current 216.632080/766: elapsed=193192.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 216.632080
last_received_ts = 216.631470
last_seq = 766
current_ts = 216.825272
current_received_ts = 216.824646
current_seq = 776
count = 38
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 216.632080/766, current 216.825272/776: elapsed=193195.0us expected=189741.9us +- 948.7us, error 1.8%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 216.632080/766, current 216.825272/776: elapsed=193195.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 216.825272
last_received_ts = 216.824646
last_seq = 776
current_ts = 217.018478
current_received_ts = 217.017868
current_seq = 786
count = 39
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 216.825272/776, current 217.018478/786: elapsed=193198.0us expected=189741.9us +- 948.7us, error 1.8%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 216.825272/776, current 217.018478/786: elapsed=193198.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 217.018478
last_received_ts = 217.017868
last_seq = 786
current_ts = 217.211670
current_received_ts = 217.211075
current_seq = 796
count = 40
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 217.018478/786, current 217.211670/796: elapsed=193195.0us expected=189741.9us +- 948.7us, error 1.8%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 217.018478/786, current 217.211670/796: elapsed=193195.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 217.211670
last_received_ts = 217.211075
last_seq = 796
current_ts = 217.404434
current_received_ts = 217.403809
current_seq = 806
count = 41
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 217.211670/796, current 217.404434/806: elapsed=192760.0us expected=189741.9us +- 948.7us, error 1.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 217.211670/796, current 217.404434/806: elapsed=192760.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 217.404434
last_received_ts = 217.403809
last_seq = 806
current_ts = 217.597198
current_received_ts = 217.596603
current_seq = 816
count = 42
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 217.404434/806, current 217.597198/816: elapsed=192776.0us expected=189741.9us +- 948.7us, error 1.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 217.404434/806, current 217.597198/816: elapsed=192776.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 217.597198
last_received_ts = 217.596603
last_seq = 816
current_ts = 217.789993
current_received_ts = 217.789383
current_seq = 826
count = 43
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 217.597198/816, current 217.789993/826: elapsed=192785.0us expected=189741.9us +- 948.7us, error 1.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 217.597198/816, current 217.789993/826: elapsed=192785.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 217.789993
last_received_ts = 217.789383
last_seq = 826
current_ts = 217.982773
current_received_ts = 217.982147
current_seq = 836
count = 44
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 217.789993/826, current 217.982773/836: elapsed=192777.0us expected=189741.9us +- 948.7us, error 1.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 217.789993/826, current 217.982773/836: elapsed=192777.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 217.982773
last_received_ts = 217.982147
last_seq = 836
current_ts = 218.175552
current_received_ts = 218.175110
current_seq = 846
count = 45
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 217.982773/836, current 218.175552/846: elapsed=192779.0us expected=189741.9us +- 948.7us, error 1.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 217.982773/836, current 218.175552/846: elapsed=192779.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 218.175552
last_received_ts = 218.175110
last_seq = 846
current_ts = 218.368011
current_received_ts = 218.367386
current_seq = 856
count = 46
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 218.175552/846, current 218.368011/856: elapsed=192460.0us expected=189741.9us +- 948.7us, error 1.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 218.175552/846, current 218.368011/856: elapsed=192460.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 218.368011
last_received_ts = 218.367386
last_seq = 856
current_ts = 218.560425
current_received_ts = 218.559799
current_seq = 866
count = 47
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 218.368011/856, current 218.560425/866: elapsed=192414.0us expected=189741.9us +- 948.7us, error 1.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 218.368011/856, current 218.560425/866: elapsed=192414.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 218.560425
last_received_ts = 218.559799
last_seq = 866
current_ts = 218.752823
current_received_ts = 218.752151
current_seq = 876
count = 48
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 218.560425/866, current 218.752823/876: elapsed=192399.0us expected=189741.9us +- 948.7us, error 1.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 218.560425/866, current 218.752823/876: elapsed=192399.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 218.752823
last_received_ts = 218.752151
last_seq = 876
current_ts = 218.945236
current_received_ts = 218.944672
current_seq = 886
count = 49
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 218.752823/876, current 218.945236/886: elapsed=192418.0us expected=189741.9us +- 948.7us, error 1.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 218.752823/876, current 218.945236/886: elapsed=192418.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 218.945236
last_received_ts = 218.944672
last_seq = 886
current_ts = 219.137634
current_received_ts = 219.136978
current_seq = 896
count = 50
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 218.945236/886, current 219.137634/896: elapsed=192400.0us expected=189741.9us +- 948.7us, error 1.4%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 218.945236/886, current 219.137634/896: elapsed=192400.0us expected=189741.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 219.137634
last_received_ts = 219.136978
last_seq = 896
current_ts = 219.329834
current_received_ts = 219.329254
current_seq = 906
count = 51
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 219.137634/896, current 219.329834/906: elapsed=192202.0us expected=189741.9us +- 948.7us, error 1.3%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 219.137634/896, current 219.329834/906: elapsed=192202.0us expected=189741.9us
(kms_flip:2349) INFO: Event vblank: expected 527, counted 520, passrate = 28.85%, encoder type 2
(kms_flip:2349) DEBUG: dropped frames, expected 527, counted 520, passrate = 28.85%, encoder type 2
(kms_flip:2349) DEBUG: Retrying without a hotplug event
(kms_flip:2349) DEBUG: No stale events found
(kms_flip:2349) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2349) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2349) INFO: Expected frametime: 18974us; measured 19134.2us +- 6.047us accuracy 0.09%
(kms_flip:2349) INFO: vblank interval differs from modeline! expected 18973.8us, measured 19134us +- 6.047us, difference 160.4us (26.5 sigma)
(kms_flip:2349) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 222.936996
current_received_ts = 222.936401
current_seq = 937
count = 0
seq_step = 10
(kms_flip:2349) DEBUG: name = vblank
last_ts = 222.936996
last_received_ts = 222.936401
last_seq = 937
current_ts = 223.128342
current_received_ts = 223.127686
current_seq = 947
count = 1
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 222.936996/937, current 223.128342/947: elapsed=191345.0us expected=191341.9us +- 956.7us, error 0.0%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 223.128342
last_received_ts = 223.127686
last_seq = 947
current_ts = 223.319580
current_received_ts = 223.318924
current_seq = 957
count = 2
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 223.128342/947, current 223.319580/957: elapsed=191241.0us expected=191341.9us +- 956.7us, error 0.1%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 223.319580
last_received_ts = 223.318924
last_seq = 957
current_ts = 223.510742
current_received_ts = 223.510101
current_seq = 967
count = 3
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 223.319580/957, current 223.510742/967: elapsed=191158.0us expected=191341.9us +- 956.7us, error 0.1%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 223.510742
last_received_ts = 223.510101
last_seq = 967
current_ts = 223.701874
current_received_ts = 223.701218
current_seq = 977
count = 4
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 223.510742/967, current 223.701874/977: elapsed=191137.0us expected=191341.9us +- 956.7us, error 0.1%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 223.701874
last_received_ts = 223.701218
last_seq = 977
current_ts = 223.893036
current_received_ts = 223.892380
current_seq = 987
count = 5
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 223.701874/977, current 223.893036/987: elapsed=191155.0us expected=191341.9us +- 956.7us, error 0.1%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 223.893036
last_received_ts = 223.892380
last_seq = 987
current_ts = 224.084198
current_received_ts = 224.083618
current_seq = 997
count = 6
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 223.893036/987, current 224.084198/997: elapsed=191162.0us expected=191341.9us +- 956.7us, error 0.1%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 224.084198
last_received_ts = 224.083618
last_seq = 997
current_ts = 224.275299
current_received_ts = 224.274704
current_seq = 1007
count = 7
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 224.084198/997, current 224.275299/1007: elapsed=191098.0us expected=191341.9us +- 956.7us, error 0.1%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 224.275299
last_received_ts = 224.274704
last_seq = 1007
current_ts = 224.466278
current_received_ts = 224.465622
current_seq = 1017
count = 8
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 224.275299/1007, current 224.466278/1017: elapsed=190979.0us expected=191341.9us +- 956.7us, error 0.2%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 224.466278
last_received_ts = 224.465622
last_seq = 1017
current_ts = 224.657272
current_received_ts = 224.656723
current_seq = 1027
count = 9
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 224.466278/1017, current 224.657272/1027: elapsed=190993.0us expected=191341.9us +- 956.7us, error 0.2%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 224.657272
last_received_ts = 224.656723
last_seq = 1027
current_ts = 224.848267
current_received_ts = 224.847610
current_seq = 1037
count = 10
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 224.657272/1027, current 224.848267/1037: elapsed=190994.0us expected=191341.9us +- 956.7us, error 0.2%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 224.848267
last_received_ts = 224.847610
last_seq = 1037
current_ts = 225.039246
current_received_ts = 225.038681
current_seq = 1047
count = 11
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 224.848267/1037, current 225.039246/1047: elapsed=190987.0us expected=191341.9us +- 956.7us, error 0.2%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 225.039246
last_received_ts = 225.038681
last_seq = 1047
current_ts = 225.230225
current_received_ts = 225.229645
current_seq = 1057
count = 12
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 225.039246/1047, current 225.230225/1057: elapsed=190971.0us expected=191341.9us +- 956.7us, error 0.2%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 225.230225
last_received_ts = 225.229645
last_seq = 1057
current_ts = 225.421066
current_received_ts = 225.420410
current_seq = 1067
count = 13
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 225.230225/1057, current 225.421066/1067: elapsed=190844.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 225.421066
last_received_ts = 225.420410
last_seq = 1067
current_ts = 225.611893
current_received_ts = 225.611237
current_seq = 1077
count = 14
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 225.421066/1067, current 225.611893/1077: elapsed=190835.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 225.611893
last_received_ts = 225.611237
last_seq = 1077
current_ts = 225.802750
current_received_ts = 225.802124
current_seq = 1087
count = 15
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 225.611893/1077, current 225.802750/1087: elapsed=190854.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 225.802750
last_received_ts = 225.802124
last_seq = 1087
current_ts = 225.993591
current_received_ts = 225.993134
current_seq = 1097
count = 16
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 225.802750/1087, current 225.993591/1097: elapsed=190842.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 225.993591
last_received_ts = 225.993134
last_seq = 1097
current_ts = 226.184433
current_received_ts = 226.183823
current_seq = 1107
count = 17
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 225.993591/1097, current 226.184433/1107: elapsed=190845.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 226.184433
last_received_ts = 226.183823
last_seq = 1107
current_ts = 226.375168
current_received_ts = 226.374603
current_seq = 1117
count = 18
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 226.184433/1107, current 226.375168/1117: elapsed=190734.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 226.375168
last_received_ts = 226.374603
last_seq = 1117
current_ts = 226.565887
current_received_ts = 226.565308
current_seq = 1127
count = 19
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 226.375168/1117, current 226.565887/1127: elapsed=190711.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 226.565887
last_received_ts = 226.565308
last_seq = 1127
current_ts = 226.756592
current_received_ts = 226.755966
current_seq = 1137
count = 20
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 226.565887/1127, current 226.756592/1137: elapsed=190714.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 226.756592
last_received_ts = 226.755966
last_seq = 1137
current_ts = 226.947311
current_received_ts = 226.946701
current_seq = 1147
count = 21
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 226.756592/1137, current 226.947311/1147: elapsed=190723.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 226.947311
last_received_ts = 226.946701
last_seq = 1147
current_ts = 227.138031
current_received_ts = 227.137421
current_seq = 1157
count = 22
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 226.947311/1147, current 227.138031/1157: elapsed=190718.0us expected=191341.9us +- 956.7us, error 0.3%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 227.138031
last_received_ts = 227.137421
last_seq = 1157
current_ts = 227.328690
current_received_ts = 227.328079
current_seq = 1167
count = 23
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 227.138031/1157, current 227.328690/1167: elapsed=190649.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 227.328690
last_received_ts = 227.328079
last_seq = 1167
current_ts = 227.519287
current_received_ts = 227.518692
current_seq = 1177
count = 24
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 227.328690/1167, current 227.519287/1177: elapsed=190600.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 227.519287
last_received_ts = 227.518692
last_seq = 1177
current_ts = 227.709885
current_received_ts = 227.709320
current_seq = 1187
count = 25
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 227.519287/1177, current 227.709885/1187: elapsed=190606.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 227.709885
last_received_ts = 227.709320
last_seq = 1187
current_ts = 227.900497
current_received_ts = 227.900040
current_seq = 1197
count = 26
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 227.709885/1187, current 227.900497/1197: elapsed=190605.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 227.900497
last_received_ts = 227.900040
last_seq = 1197
current_ts = 228.091110
current_received_ts = 228.090546
current_seq = 1207
count = 27
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 227.900497/1197, current 228.091110/1207: elapsed=190610.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 228.091110
last_received_ts = 228.090546
last_seq = 1207
current_ts = 228.281693
current_received_ts = 228.281067
current_seq = 1217
count = 28
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 228.091110/1207, current 228.281693/1217: elapsed=190581.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 228.281693
last_received_ts = 228.281067
last_seq = 1217
current_ts = 228.472183
current_received_ts = 228.471558
current_seq = 1227
count = 29
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 228.281693/1217, current 228.472183/1227: elapsed=190497.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 228.472183
last_received_ts = 228.471558
last_seq = 1227
current_ts = 228.662689
current_received_ts = 228.662079
current_seq = 1237
count = 30
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 228.472183/1227, current 228.662689/1237: elapsed=190511.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 228.662689
last_received_ts = 228.662079
last_seq = 1237
current_ts = 228.853210
current_received_ts = 228.852570
current_seq = 1247
count = 31
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 228.662689/1237, current 228.853210/1247: elapsed=190509.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 228.853210
last_received_ts = 228.852570
last_seq = 1247
current_ts = 229.043732
current_received_ts = 229.043091
current_seq = 1257
count = 32
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 228.853210/1247, current 229.043732/1257: elapsed=190523.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 229.043732
last_received_ts = 229.043091
last_seq = 1257
current_ts = 229.234222
current_received_ts = 229.233597
current_seq = 1267
count = 33
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 229.043732/1257, current 229.234222/1267: elapsed=190492.0us expected=191341.9us +- 956.7us, error 0.4%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 229.234222
last_received_ts = 229.233597
last_seq = 1267
current_ts = 229.424637
current_received_ts = 229.424042
current_seq = 1277
count = 34
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 229.234222/1267, current 229.424637/1277: elapsed=190419.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 229.424637
last_received_ts = 229.424042
last_seq = 1277
current_ts = 229.615067
current_received_ts = 229.614502
current_seq = 1287
count = 35
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 229.424637/1277, current 229.615067/1287: elapsed=190426.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 229.615067
last_received_ts = 229.614502
last_seq = 1287
current_ts = 229.805496
current_received_ts = 229.804962
current_seq = 1297
count = 36
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 229.615067/1287, current 229.805496/1297: elapsed=190436.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 229.805496
last_received_ts = 229.804962
last_seq = 1297
current_ts = 229.995911
current_received_ts = 229.995300
current_seq = 1307
count = 37
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 229.805496/1297, current 229.995911/1307: elapsed=190412.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 229.995911
last_received_ts = 229.995300
last_seq = 1307
current_ts = 230.186356
current_received_ts = 230.185669
current_seq = 1317
count = 38
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 229.995911/1307, current 230.186356/1317: elapsed=190436.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: name = vblank
last_ts = 230.186356
last_received_ts = 230.185669
last_seq = 1317
current_ts = 230.376694
current_received_ts = 230.376099
current_seq = 1327
count = 39
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 230.186356/1317, current 230.376694/1327: elapsed=190352.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 230.186356/1317, current 230.376694/1327: elapsed=190352.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 230.376694
last_received_ts = 230.376099
last_seq = 1327
current_ts = 230.567047
current_received_ts = 230.566437
current_seq = 1337
count = 40
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 230.376694/1327, current 230.567047/1337: elapsed=190351.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 230.376694/1327, current 230.567047/1337: elapsed=190351.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 230.567047
last_received_ts = 230.566437
last_seq = 1337
current_ts = 230.757401
current_received_ts = 230.756882
current_seq = 1347
count = 41
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 230.567047/1337, current 230.757401/1347: elapsed=190356.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 230.567047/1337, current 230.757401/1347: elapsed=190356.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 230.757401
last_received_ts = 230.756882
last_seq = 1347
current_ts = 230.947754
current_received_ts = 230.947144
current_seq = 1357
count = 42
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 230.757401/1347, current 230.947754/1357: elapsed=190347.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 230.757401/1347, current 230.947754/1357: elapsed=190347.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 230.947754
last_received_ts = 230.947144
last_seq = 1357
current_ts = 231.138107
current_received_ts = 231.137543
current_seq = 1367
count = 43
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 230.947754/1357, current 231.138107/1367: elapsed=190353.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 230.947754/1357, current 231.138107/1367: elapsed=190353.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 231.138107
last_received_ts = 231.137543
last_seq = 1367
current_ts = 231.328430
current_received_ts = 231.327805
current_seq = 1377
count = 44
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 231.138107/1367, current 231.328430/1377: elapsed=190318.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 231.138107/1367, current 231.328430/1377: elapsed=190318.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 231.328430
last_received_ts = 231.327805
last_seq = 1377
current_ts = 231.518707
current_received_ts = 231.518097
current_seq = 1387
count = 45
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 231.328430/1377, current 231.518707/1387: elapsed=190286.0us expected=191341.9us +- 956.7us, error 0.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 231.328430/1377, current 231.518707/1387: elapsed=190286.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 231.518707
last_received_ts = 231.518097
last_seq = 1387
current_ts = 231.708984
current_received_ts = 231.708496
current_seq = 1397
count = 46
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 231.518707/1387, current 231.708984/1397: elapsed=190279.0us expected=191341.9us +- 956.7us, error 0.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 231.518707/1387, current 231.708984/1397: elapsed=190279.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 231.708984
last_received_ts = 231.708496
last_seq = 1397
current_ts = 231.899292
current_received_ts = 231.898758
current_seq = 1407
count = 47
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 231.708984/1397, current 231.899292/1407: elapsed=190296.0us expected=191341.9us +- 956.7us, error 0.5%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 231.708984/1397, current 231.899292/1407: elapsed=190296.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 231.899292
last_received_ts = 231.898758
last_seq = 1407
current_ts = 232.089569
current_received_ts = 232.088959
current_seq = 1417
count = 48
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 231.899292/1407, current 232.089569/1417: elapsed=190285.0us expected=191341.9us +- 956.7us, error 0.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 231.899292/1407, current 232.089569/1417: elapsed=190285.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 232.089569
last_received_ts = 232.088959
last_seq = 1417
current_ts = 232.279831
current_received_ts = 232.279205
current_seq = 1427
count = 49
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 232.089569/1417, current 232.279831/1427: elapsed=190263.0us expected=191341.9us +- 956.7us, error 0.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 232.089569/1417, current 232.279831/1427: elapsed=190263.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 232.279831
last_received_ts = 232.279205
last_seq = 1427
current_ts = 232.470062
current_received_ts = 232.469482
current_seq = 1437
count = 50
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 232.279831/1427, current 232.470062/1437: elapsed=190220.0us expected=191341.9us +- 956.7us, error 0.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 232.279831/1427, current 232.470062/1437: elapsed=190220.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 232.470062
last_received_ts = 232.469482
last_seq = 1437
current_ts = 232.660294
current_received_ts = 232.659683
current_seq = 1447
count = 51
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 232.470062/1437, current 232.660294/1447: elapsed=190243.0us expected=191341.9us +- 956.7us, error 0.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 232.470062/1437, current 232.660294/1447: elapsed=190243.0us expected=191341.9us
(kms_flip:2349) DEBUG: name = vblank
last_ts = 232.660294
last_received_ts = 232.659683
last_seq = 1447
current_ts = 232.850525
current_received_ts = 232.849976
current_seq = 1457
count = 52
seq_step = 10
(kms_flip:2349) DEBUG: vblank ts/seq: last 232.660294/1447, current 232.850525/1457: elapsed=190231.0us expected=191341.9us +- 956.7us, error 0.6%
(kms_flip:2349) DEBUG: inconsistent vblank ts/seq: last 232.660294/1447, current 232.850525/1457: elapsed=190231.0us expected=191341.9us
(kms_flip:2349) INFO: Event vblank: expected 528, counted 530, passrate = 73.58%, encoder type 2
(kms_flip:2349) DEBUG: dropped frames, expected 528, counted 530, passrate = 73.58%, encoder type 2
(kms_flip:2349) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1722:
(kms_flip:2349) CRITICAL: Failed assertion: !retried
(kms_flip:2349) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2349) igt_core-INFO: Stack trace:
(kms_flip:2349) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2349) igt_core-INFO:   #1 ../tests/kms_flip.c:1071 run_test_on_crtc_set()
(kms_flip:2349) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2349) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2349) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2349) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2349) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2349) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-HDMI-A2: FAIL (23.804s)
Subtest wf_vblank-ts-check-interruptible: FAIL (44.842s)
(kms_flip:2349) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2352:
(kms_flip:2349) igt_kms-CRITICAL: Failed assertion: found_it
(kms_flip:2349) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
(kms_flip:2349) igt_kms-CRITICAL: DPMS property not found on 400
Dmesg
<6> [239.350544] [IGT] kms_flip: starting dynamic subtest C-HDMI-A2
<7> [239.350881] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:417]
<7> [239.350963] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:419]
<7> [239.367855] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [239.367989] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [239.368049] 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> [239.368251] 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> [239.368397] 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> [239.368536] 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> [239.368682] 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> [239.368825] 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> [239.368961] 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> [239.369103] 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> [239.369236] 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> [239.369369] 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> [239.369502] 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> [239.369635] 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> [239.369784] 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> [239.369922] 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> [239.370054] 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> [239.370188] 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> [239.370320] 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> [239.370453] 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> [239.370587] 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> [239.370735] 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> [239.370915] 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> [239.371047] 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> [239.371180] 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> [239.371312] 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> [239.371443] 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> [239.371575] 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> [239.371714] 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> [239.371846] 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> [239.371979] 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> [239.372113] 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> [239.372245] 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> [239.372376] 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> [239.372508] 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> [239.372640] 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> [239.372818] 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> [239.372951] 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> [239.373084] 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> [239.373217] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:269:pipe B] fastset requirement not met, forcing full modeset
<7> [239.373351] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:269:pipe B] releasing DPLL 0
<7> [239.373504] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no
<7> [239.373637] 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> [239.373807] 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> [239.373954] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:269:pipe B] min cdclk: 69965 kHz -> 0 kHz
<7> [239.374093] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:269:pipe B] enable: no [modeset]
<7> [239.374228] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 1B] fb: [NOFB], visible: no
<7> [239.374364] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:183:plane 2B] fb: [NOFB], visible: no
<7> [239.374498] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:213:plane 3B] fb: [NOFB], visible: no
<7> [239.374632] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:243:plane 4B] fb: [NOFB], visible: no
<7> [239.374777] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:253:plane 5B] fb: [NOFB], visible: no
<7> [239.374915] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:263:cursor B] fb: [NOFB], visible: no
<7> [239.375233] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B
<7> [239.383918] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC1
<7> [239.384084] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:269:pipe B]
<7> [239.384242] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [239.384391] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [239.384528] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [239.384693] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [239.384832] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [239.384966] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [239.385099] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [239.385231] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:400:HDMI-A-2]
<7> [239.385424] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [239.385603] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3
<7> [239.385792] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:269:pipe B]
<7> [239.386104] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [239.386236] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [239.386258] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:400:HDMI-A-2]
<7> [239.386314] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:400:HDMI-A-2] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)
<7> [239.386461] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [239.386588] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [239.386737] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:399:DDI TC1/PHY C] [CRTC:387:pipe C]
<7> [239.386867] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.enable (expected no, found yes)
<7> [239.387004] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.active (expected no, found yes)
<7> [239.387138] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)
<7> [239.387273] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in lane_count (expected 0, found 4)
<7> [239.387407] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [239.387540] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [239.387680] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [239.387814] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360)
<7> [239.387947] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [239.388080] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360)
<7> [239.388213] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [239.388346] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096)
<7> [239.388480] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [239.388613] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [239.388760] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [239.388894] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [239.389031] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [239.389163] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [239.389296] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [239.389430] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360)
<7> [239.389562] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [239.389704] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360)
<7> [239.389836] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [239.389968] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096)
<7> [239.390099] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [239.390231] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [239.390364] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [239.390495] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [239.390628] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [239.390774] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [239.390906] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [239.391039] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [239.391171] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [239.391303] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [239.391436] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929)
<7> [239.391568] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929)
<7> [239.391709] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 0, found 139929)
<7> [239.391843] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset
<7> [239.391996] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no
<7> [239.392130] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4
<7> [239.392282] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016
<7> [239.392413] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32
<7> [239.392544] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [239.392683] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0
<7> [239.392817] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0
<7> [239.392948] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] 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> [239.393094] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 559716 num active planes 1
<7> [239.393231] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560
<7> [239.393364] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [239.393510] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 0 kHz -> 69965 kHz
<7> [239.393666] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:387:pipe C] allocated DPLL 0
<7> [239.393806] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:387:pipe C] reserving DPLL 0
<7> [239.393943] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: yes [modeset]
<7> [239.394078] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [239.394212] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: C, pipe bpp: 24, dithering: 0
<7> [239.394348] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [239.394481] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [239.394613] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [239.394789] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [239.394921] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [239.395052] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [239.395182] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [239.395312] 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> [239.395443] 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> [239.395575] 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> [239.395719] 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> [239.395850] 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> [239.395980] 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> [239.396111] 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> [239.396241] 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> [239.396372] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0
<7> [239.396502] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0
<7> [239.396633] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [239.396780] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [239.396911] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [239.397042] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [239.397172] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [239.397302] 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> [239.397433] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [239.397562] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [239.397702] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [239.397833] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [239.397963] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [239.398093] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [239.398223] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [239.398353] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [239.398482] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [239.398613] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [239.398761] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [239.398894] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [239.399028] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [FB:417] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [239.399162] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [239.399294] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [239.399427] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no
<7> [239.399558] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no
<7> [239.399699] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no
<7> [239.399830] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no
<7> [239.399962] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no
<7> [239.400581] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3
<7> [239.400748] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_4
<7> [239.400909] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [239.401046] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [239.401181] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [239.401318] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [239.401454] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [239.401587] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [239.401772] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [239.401944] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:387:pipe C]
<7> [239.402082] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [239.402275] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC1
<7> [239.402450] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe C
<7> [239.422524] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:400:HDMI-A-2]
<7> [239.422793] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C]
<6> [249.741791] pcieport 0000:00:06.0: AER: Correctable error message received from 0000:01:00.0
<4> [249.741813] nvme 0000:01:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
<4> [249.741820] nvme 0000:01:00.0: device [15b7:5006] error status/mask=00000001/0000e000
<4> [249.741828] nvme 0000:01:00.0: [ 0] RxErr (First)
<7> [252.601993] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [252.602507] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [252.603014] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [252.603259] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.enable (expected yes, found no)
<7> [252.603972] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.active (expected yes, found no)
<7> [252.604643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1)
<7> [252.605562] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in lane_count (expected 4, found 0)
<7> [252.606238] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [252.606896] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [252.607518] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [252.608178] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0)
<7> [252.608826] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [252.609235] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0)
<7> [252.609369] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [252.609502] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0)
<7> [252.609636] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [252.609775] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [252.609908] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [252.610041] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [252.610174] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [252.610307] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [252.610439] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [252.610571] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0)
<7> [252.610705] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [252.610854] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0)
<7> [252.610988] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [252.611121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0)
<7> [252.611254] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [252.611387] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [252.611520] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [252.611652] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [252.611801] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [252.611935] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [252.612068] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [252.612201] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [252.612334] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [252.612467] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [252.612601] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0)
<7> [252.612739] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0)
<7> [252.612873] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 139929, found 0)
<7> [252.613006] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset
<7> [252.613140] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:387:pipe C] releasing DPLL 0
<7> [252.613292] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no
<7> [252.613425] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x4 -> 0x0
<7> [252.613577] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0
<7> [252.613711] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0
<7> [252.613843] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [252.613976] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [252.614106] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [252.614237] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] 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> [252.614381] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 0 num active planes 0
<7> [252.614517] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0
<7> [252.614650] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [252.614818] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 69965 kHz -> 0 kHz
<7> [252.614969] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 8746 kHz -> 0 kHz
<7> [252.615105] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: no [modeset]
<7> [252.615243] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [NOFB], visible: no
<7> [252.615380] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no
<7> [252.615515] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no
<7> [252.615648] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no
<7> [252.615801] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no
<7> [252.615933] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no
<7> [252.616178] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe C
<7> [252.628810] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC1
<7> [252.628977] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x4, on? 1) for [CRTC:387:pipe C]
<7> [252.629139] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [252.629340] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [252.629527] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [252.629770] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [252.629952] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [252.630132] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [252.630313] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [252.630492] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:400:HDMI-A-2]
<7> [252.630768] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [252.630996] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_4
<7> [252.631204] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3
<7> [252.631417] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C]
<7> [252.631839] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [252.631868] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:400:HDMI-A-2]
<7> [252.631938] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:400:HDMI-A-2] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)
<7> [252.632131] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [252.632298] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [252.632472] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:399:DDI TC1/PHY C] [CRTC:387:pipe C]
<7> [252.632640] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.enable (expected no, found yes)
<7> [252.632804] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.active (expected no, found yes)
<7> [252.632964] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)
<7> [252.633124] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in lane_count (expected 0, found 4)
<7> [252.633290] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [252.633453] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [252.633626] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [252.633790] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360)
<7> [252.633950] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [252.634108] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360)
<7> [252.634266] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [252.634422] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096)
<7> [252.634589] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [252.634752] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [252.634915] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [252.635071] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [252.635232] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [252.635365] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [252.635498] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [252.635647] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360)
<7> [252.635780] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [252.635913] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360)
<7> [252.636047] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [252.636179] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096)
<7> [252.636310] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [252.636443] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [252.636591] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [252.636724] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [252.636857] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [252.636990] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [252.637122] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [252.637255] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [252.637388] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [252.637531] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [252.637663] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929)
<7> [252.637796] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929)
<7> [252.637928] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 0, found 139929)
<7> [252.638089] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset
<7> [252.638269] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no
<7> [252.638405] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4
<7> [252.638570] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016
<7> [252.638701] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32
<7> [252.638839] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [252.638969] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0
<7> [252.639109] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0
<7> [252.639238] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] 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> [252.639381] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 559716 num active planes 1
<7> [252.639534] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560
<7> [252.639669] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [252.639814] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 0 kHz -> 69965 kHz
<7> [252.639959] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 8746 kHz
<7> [252.640093] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:387:pipe C] allocated DPLL 0
<7> [252.640231] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:387:pipe C] reserving DPLL 0
<7> [252.640418] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: yes [modeset]
<7> [252.640613] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [252.640749] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: C, pipe bpp: 24, dithering: 0
<7> [252.640883] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [252.641015] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [252.641146] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [252.641278] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [252.641409] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [252.641555] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [252.641686] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [252.641817] 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> [252.641956] 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> [252.642088] 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> [252.642233] 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> [252.642370] 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> [252.642516] 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> [252.642651] 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> [252.642785] 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> [252.642917] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0
<7> [252.643101] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0
<7> [252.643239] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [252.643378] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [252.643524] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [252.643666] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [252.643797] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [252.643929] 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> [252.644064] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [252.644230] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [252.644363] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [252.644517] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [252.644647] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [252.644786] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [252.644917] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [252.645047] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [252.645207] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [252.645345] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [252.645499] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [252.645630] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [252.645768] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [FB:417] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [252.645901] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [252.646032] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [252.646164] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no
<7> [252.646304] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no
<7> [252.646501] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no
<7> [252.646638] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no
<7> [252.646780] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no
<7> [252.646999] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3
<7> [252.647151] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_4
<7> [252.647311] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [252.647471] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [252.647635] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [252.647771] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [252.647912] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [252.648052] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [252.648228] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [252.648409] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:387:pipe C]
<7> [252.648561] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [252.648778] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC1
<7> [252.648960] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe C
<7> [252.668910] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:400:HDMI-A-2]
<7> [252.669176] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C]
<6> [263.154938] [IGT] kms_flip: finished subtest C-HDMI-A2, FAIL
<6> [263.155926] [IGT] kms_flip: finished subtest wf_vblank-ts-check-interruptible, FAIL
<7> [263.158667] i915 0000:00:02.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:419] from all active usage due to RMFB ioctl
<7> [263.158703] i915 0000:00:02.0: [drm:atomic_remove_fb] Disabling [PLANE:271:plane 1C] because [FB:419] is removed
<7> [263.158742] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0
<7> [263.158908] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [263.159049] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [263.159183] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [263.159317] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] 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> [263.159490] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 0 num active planes 0
<7> [263.159630] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0
<7> [263.159768] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<6> [263.162013] [IGT] kms_flip: exiting, ret=98
<7> [263.174214] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:400:HDMI-A-2] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)
<7> [263.174417] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [263.174572] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [263.174726] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:399:DDI TC1/PHY C] [CRTC:151:pipe A]
<7> [263.174866] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [263.175010] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [263.175171] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [263.175316] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [263.175458] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [263.175592] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [263.175735] 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 0, found 1920)
<7> [263.175906] 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 0, found 2360)
<7> [263.176041] 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 0, found 1920)
<7> [263.176181] 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 0, found 2360)
<7> [263.176321] 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 0, found 2008)
<7> [263.176486] 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 0, found 2096)
<7> [263.176642] 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 0, found 1080)
<7> [263.176780] 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 0, found 1080)
<7> [263.176920] 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 0, found 1084)
<7> [263.177062] 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 0, found 1089)
<7> [263.177220] 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 0, found 1125)
<7> [263.177443] 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 0, found 1125)
<7> [263.177582] 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 0, found 1920)
<7> [263.177722] 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 0, found 2360)
<7> [263.177884] 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 0, found 1920)
<7> [263.178029] 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 0, found 2360)
<7> [263.178173] 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 0, found 2008)
<7> [263.178418] 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 0, found 2096)
<7> [263.178612] 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 0, found 1080)
<7> [263.178790] 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 0, found 1080)
<7> [263.178925] 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 0, found 1084)
<7> [263.179059] 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 0, found 1089)
<7> [263.179195] 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 0, found 1125)
<7> [263.179345] 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 0, found 1125)
<7> [263.179478] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [263.179612] 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 0, found 1)
<7> [263.179746] 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 0, found 4)
<7> [263.179880] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [263.180013] 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 0, found 139929)
<7> [263.180146] 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 0, found 139929)
<7> [263.180279] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 139929)
<7> [263.180426] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [263.180559] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.enable (expected yes, found no)
<7> [263.180692] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.active (expected yes, found no)
<7> [263.180824] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1)
<7> [263.180957] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in lane_count (expected 4, found 0)
<7> [263.181090] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [263.181222] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [263.181364] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [263.181497] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0)
<7> [263.181630] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [263.181762] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0)
<7> [263.181894] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [263.182026] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0)
<7> [263.182158] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [263.182297] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [263.182430] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [263.182563] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [263.182696] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [263.182828] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [263.182960] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [263.183093] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0)
<7> [263.183226] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [263.183369] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0)
<7> [263.183501] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [263.183633] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0)
<7> [263.183766] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [263.183899] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [263.184031] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [263.184165] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [263.184333] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [263.184467] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [263.184599] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [263.184732] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [263.184865] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [263.184997] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [263.185129] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0)
<7> [263.185262] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0)
<7> [263.185407] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 139929, found 0)
<7> [263.185539] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset
<7> [263.185672] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:387:pipe C] releasing DPLL 0
<7> [263.185842] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x4 -> 0x1
<7> [263.185976] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x4 -> 0x1
<7> [263.186112] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016
<7> [263.186244] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32
<7> [263.186389] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [263.186519] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0
<7> [263.186649] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0
<7> [263.186778] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0
<7> [263.186912] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0
<7> [263.187061] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 559716 num active planes 1
<7> [263.187199] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560
<7> [263.187376] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [263.187592] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 69965 kHz
<7> [263.187792] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 69965 kHz -> 0 kHz
<7> [263.187983] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:151:pipe A] allocated DPLL 0
<7> [263.188123] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:151:pipe A] reserving DPLL 0
<7> [263.188274] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [263.188413] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [263.188548] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [263.188683] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [263.188818] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [263.188952] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [263.189087] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [263.189220] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [263.189366] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [263.189504] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [263.189640] 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> [263.189775] 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> [263.189908] 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> [263.190041] 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> [263.190175] 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> [263.190318] 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> [263.190451] 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> [263.190584] 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> [263.190716] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0
<7> [263.190849] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0
<7> [263.190981] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [263.191114] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [263.191246] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [263.191392] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [263.191524] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [263.191656] 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> [263.191790] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [263.191921] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [263.192053] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [263.192185] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [263.192355] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [263.192487] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [263.192619] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [263.192749] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [263.192880] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [263.193011] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [263.193144] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [263.193283] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [263.193415] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:416] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [263.193551] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [263.193687] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [263.193823] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [263.193958] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [263.194093] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [263.194226] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [263.194375] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [263.194508] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: no [modeset]
<7> [263.194640] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [NOFB], visible: no
<7> [263.194773] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no
<7> [263.194905] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no
<7> [263.195038] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no
<7> [263.195170] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no
<7> [263.195312] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no
<7> [263.195592] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe C
<7> [263.200290] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC1
<7> [263.200444] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x4, on? 1) for [CRTC:387:pipe C]
<7> [263.200604] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [263.200751] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B]
<7> [263.200889] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]
<7> [263.201026] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]
<7> [263.201162] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]
<7> [263.201316] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]
<7> [263.201498] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]
<7> [263.201824] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]
<7> [263.202011] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [263.202420] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC1
<7> [263.202602] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [263.202998] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [263.203137] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]
<7> [263.222084] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:400:HDMI-A-2]
<7> [263.222313] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<7> [263.222804] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_4
<7> [263.222975] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C]
<7> [263.223350] i915 0000:00:02.0: [drm:drm_client_dev_restore] fbdev: ret=0
Created at 2026-04-27 18:49:21