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

Result: Fail

integration-manifest git-log-oneline i915_display_info12 igt_runner12 runtimes12 results12.json results12-i915-load.json guc_logs12.tar i915_display_info_post_exec12 boot12 dmesg12

DetailValue
Duration 18.96 seconds
Hostname 
shard-snb5
Igt-Version 
IGT-Version: 2.3-g476cbad7c (x86_64) (Linux: 7.0.0-rc3-Patchwork_162934v1-g77e176657e78+ x86_64)
Out 
Starting dynamic subtest: A-HDMI-A1
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Expected frametime: 16667us; measured 16640.2us +- 6.698us accuracy 0.12%
vblank interval differs from modeline! expected 16666.7us, measured 16640us +- 6.698us, difference 26.4us (3.9 sigma)
Event vblank: expected 459, counted 450, passrate = 35.56%, encoder type 2
Expected frametime: 16667us; measured 16878.2us +- 6.327us accuracy 0.11%
vblank interval differs from modeline! expected 16666.7us, measured 16878us +- 6.327us, difference 211.5us (33.4 sigma)
Event vblank: expected 447, counted 450, passrate = 46.67%, encoder type 2
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A1: FAIL (18.965s)
Err 
Starting dynamic subtest: A-HDMI-A1
(kms_flip:2889) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1707:
(kms_flip:2889) CRITICAL: Failed assertion: !retried
(kms_flip:2889) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-HDMI-A1 failed.
**** DEBUG ****
(kms_flip:2889) INFO: Expected frametime: 16667us; measured 16640.2us +- 6.698us accuracy 0.12%
(kms_flip:2889) INFO: vblank interval differs from modeline! expected 16666.7us, measured 16640us +- 6.698us, difference 26.4us (3.9 sigma)
(kms_flip:2889) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 296.528900
current_received_ts = 296.528351
current_seq = 10507
count = 0
seq_step = 10
(kms_flip:2889) DEBUG: name = vblank
last_ts = 296.528900
last_received_ts = 296.528351
last_seq = 10507
current_ts = 296.695312
current_received_ts = 296.694855
current_seq = 10517
count = 1
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 296.528900/10507, current 296.695312/10517: elapsed=166411.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 296.695312
last_received_ts = 296.694855
last_seq = 10517
current_ts = 296.861694
current_received_ts = 296.861206
current_seq = 10527
count = 2
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 296.695312/10517, current 296.861694/10527: elapsed=166400.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 296.861694
last_received_ts = 296.861206
last_seq = 10527
current_ts = 297.028107
current_received_ts = 297.027618
current_seq = 10537
count = 3
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 296.861694/10527, current 297.028107/10537: elapsed=166406.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 297.028107
last_received_ts = 297.027618
last_seq = 10537
current_ts = 297.194519
current_received_ts = 297.194061
current_seq = 10547
count = 4
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 297.028107/10537, current 297.194519/10547: elapsed=166413.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 297.194519
last_received_ts = 297.194061
last_seq = 10547
current_ts = 297.360931
current_received_ts = 297.360474
current_seq = 10557
count = 5
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 297.194519/10547, current 297.360931/10557: elapsed=166418.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 297.360931
last_received_ts = 297.360474
last_seq = 10557
current_ts = 297.527344
current_received_ts = 297.526855
current_seq = 10567
count = 6
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 297.360931/10557, current 297.527344/10567: elapsed=166401.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 297.527344
last_received_ts = 297.526855
last_seq = 10567
current_ts = 297.693756
current_received_ts = 297.693176
current_seq = 10577
count = 7
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 297.527344/10567, current 297.693756/10577: elapsed=166411.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 297.693756
last_received_ts = 297.693176
last_seq = 10577
current_ts = 297.860168
current_received_ts = 297.859650
current_seq = 10587
count = 8
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 297.693756/10577, current 297.860168/10587: elapsed=166404.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 297.860168
last_received_ts = 297.859650
last_seq = 10587
current_ts = 298.026581
current_received_ts = 298.025970
current_seq = 10597
count = 9
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 297.860168/10587, current 298.026581/10597: elapsed=166415.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 298.026581
last_received_ts = 298.025970
last_seq = 10597
current_ts = 298.192993
current_received_ts = 298.192505
current_seq = 10607
count = 10
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 298.026581/10597, current 298.192993/10607: elapsed=166410.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 298.192993
last_received_ts = 298.192505
last_seq = 10607
current_ts = 298.359406
current_received_ts = 298.358917
current_seq = 10617
count = 11
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 298.192993/10607, current 298.359406/10617: elapsed=166409.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 298.359406
last_received_ts = 298.358917
last_seq = 10617
current_ts = 298.525787
current_received_ts = 298.525238
current_seq = 10627
count = 12
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 298.359406/10617, current 298.525787/10627: elapsed=166395.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 298.525787
last_received_ts = 298.525238
last_seq = 10627
current_ts = 298.692200
current_received_ts = 298.691681
current_seq = 10637
count = 13
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 298.525787/10627, current 298.692200/10637: elapsed=166413.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 298.692200
last_received_ts = 298.691681
last_seq = 10637
current_ts = 298.858612
current_received_ts = 298.858124
current_seq = 10647
count = 14
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 298.692200/10637, current 298.858612/10647: elapsed=166421.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 298.858612
last_received_ts = 298.858124
last_seq = 10647
current_ts = 299.025024
current_received_ts = 299.024567
current_seq = 10657
count = 15
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 298.858612/10647, current 299.025024/10657: elapsed=166411.0us expected=166402.5us +- 832.0us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 299.025024
last_received_ts = 299.024567
last_seq = 10657
current_ts = 299.195374
current_received_ts = 299.194855
current_seq = 10667
count = 16
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 299.025024/10657, current 299.195374/10667: elapsed=170346.0us expected=166402.5us +- 832.0us, error 2.4%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 299.025024/10657, current 299.195374/10667: elapsed=170346.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 299.195374
last_received_ts = 299.194855
last_seq = 10667
current_ts = 299.368683
current_received_ts = 299.368103
current_seq = 10677
count = 17
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 299.195374/10667, current 299.368683/10677: elapsed=173316.0us expected=166402.5us +- 832.0us, error 4.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 299.195374/10667, current 299.368683/10677: elapsed=173316.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 299.368683
last_received_ts = 299.368103
last_seq = 10677
current_ts = 299.542023
current_received_ts = 299.541473
current_seq = 10687
count = 18
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 299.368683/10677, current 299.542023/10687: elapsed=173315.0us expected=166402.5us +- 832.0us, error 4.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 299.368683/10677, current 299.542023/10687: elapsed=173315.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 299.542023
last_received_ts = 299.541473
last_seq = 10687
current_ts = 299.715332
current_received_ts = 299.714844
current_seq = 10697
count = 19
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 299.542023/10687, current 299.715332/10697: elapsed=173311.0us expected=166402.5us +- 832.0us, error 4.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 299.542023/10687, current 299.715332/10697: elapsed=173311.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 299.715332
last_received_ts = 299.714844
last_seq = 10697
current_ts = 299.888641
current_received_ts = 299.888092
current_seq = 10707
count = 20
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 299.715332/10697, current 299.888641/10707: elapsed=173324.0us expected=166402.5us +- 832.0us, error 4.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 299.715332/10697, current 299.888641/10707: elapsed=173324.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 299.888641
last_received_ts = 299.888092
last_seq = 10707
current_ts = 300.061981
current_received_ts = 300.061432
current_seq = 10717
count = 21
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 299.888641/10707, current 300.061981/10717: elapsed=173319.0us expected=166402.5us +- 832.0us, error 4.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 299.888641/10707, current 300.061981/10717: elapsed=173319.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 300.061981
last_received_ts = 300.061432
last_seq = 10717
current_ts = 300.234589
current_received_ts = 300.234131
current_seq = 10727
count = 22
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 300.061981/10717, current 300.234589/10727: elapsed=172624.0us expected=166402.5us +- 832.0us, error 3.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 300.061981/10717, current 300.234589/10727: elapsed=172624.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 300.234589
last_received_ts = 300.234131
last_seq = 10727
current_ts = 300.407043
current_received_ts = 300.406555
current_seq = 10737
count = 23
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 300.234589/10727, current 300.407043/10737: elapsed=172458.0us expected=166402.5us +- 832.0us, error 3.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 300.234589/10727, current 300.407043/10737: elapsed=172458.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 300.407043
last_received_ts = 300.406555
last_seq = 10737
current_ts = 300.579498
current_received_ts = 300.579010
current_seq = 10747
count = 24
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 300.407043/10737, current 300.579498/10747: elapsed=172440.0us expected=166402.5us +- 832.0us, error 3.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 300.407043/10737, current 300.579498/10747: elapsed=172440.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 300.579498
last_received_ts = 300.579010
last_seq = 10747
current_ts = 300.751953
current_received_ts = 300.751434
current_seq = 10757
count = 25
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 300.579498/10747, current 300.751953/10757: elapsed=172460.0us expected=166402.5us +- 832.0us, error 3.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 300.579498/10747, current 300.751953/10757: elapsed=172460.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 300.751953
last_received_ts = 300.751434
last_seq = 10757
current_ts = 300.924408
current_received_ts = 300.923981
current_seq = 10767
count = 26
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 300.751953/10757, current 300.924408/10767: elapsed=172462.0us expected=166402.5us +- 832.0us, error 3.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 300.751953/10757, current 300.924408/10767: elapsed=172462.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 300.924408
last_received_ts = 300.923981
last_seq = 10767
current_ts = 301.096863
current_received_ts = 301.096436
current_seq = 10777
count = 27
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 300.924408/10767, current 301.096863/10777: elapsed=172448.0us expected=166402.5us +- 832.0us, error 3.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 300.924408/10767, current 301.096863/10777: elapsed=172448.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 301.096863
last_received_ts = 301.096436
last_seq = 10777
current_ts = 301.268555
current_received_ts = 301.268036
current_seq = 10787
count = 28
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 301.096863/10777, current 301.268555/10787: elapsed=171701.0us expected=166402.5us +- 832.0us, error 3.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 301.096863/10777, current 301.268555/10787: elapsed=171701.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 301.268555
last_received_ts = 301.268036
last_seq = 10787
current_ts = 301.440247
current_received_ts = 301.439758
current_seq = 10797
count = 29
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 301.268555/10787, current 301.440247/10797: elapsed=171699.0us expected=166402.5us +- 832.0us, error 3.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 301.268555/10787, current 301.440247/10797: elapsed=171699.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 301.440247
last_received_ts = 301.439758
last_seq = 10797
current_ts = 301.611938
current_received_ts = 301.611481
current_seq = 10807
count = 30
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 301.440247/10797, current 301.611938/10807: elapsed=171687.0us expected=166402.5us +- 832.0us, error 3.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 301.440247/10797, current 301.611938/10807: elapsed=171687.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 301.611938
last_received_ts = 301.611481
last_seq = 10807
current_ts = 301.783661
current_received_ts = 301.783112
current_seq = 10817
count = 31
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 301.611938/10807, current 301.783661/10817: elapsed=171708.0us expected=166402.5us +- 832.0us, error 3.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 301.611938/10807, current 301.783661/10817: elapsed=171708.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 301.783661
last_received_ts = 301.783112
last_seq = 10817
current_ts = 301.955353
current_received_ts = 301.954834
current_seq = 10827
count = 32
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 301.783661/10817, current 301.955353/10827: elapsed=171689.0us expected=166402.5us +- 832.0us, error 3.2%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 301.783661/10817, current 301.955353/10827: elapsed=171689.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 301.955353
last_received_ts = 301.954834
last_seq = 10827
current_ts = 302.126923
current_received_ts = 302.126404
current_seq = 10837
count = 33
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 301.955353/10827, current 302.126923/10837: elapsed=171591.0us expected=166402.5us +- 832.0us, error 3.1%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 301.955353/10827, current 302.126923/10837: elapsed=171591.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 302.126923
last_received_ts = 302.126404
last_seq = 10837
current_ts = 302.297974
current_received_ts = 302.297363
current_seq = 10847
count = 34
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 302.126923/10837, current 302.297974/10847: elapsed=171036.0us expected=166402.5us +- 832.0us, error 2.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 302.126923/10837, current 302.297974/10847: elapsed=171036.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 302.297974
last_received_ts = 302.297363
last_seq = 10847
current_ts = 302.468994
current_received_ts = 302.468414
current_seq = 10857
count = 35
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 302.297974/10847, current 302.468994/10857: elapsed=171036.0us expected=166402.5us +- 832.0us, error 2.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 302.297974/10847, current 302.468994/10857: elapsed=171036.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 302.468994
last_received_ts = 302.468414
last_seq = 10857
current_ts = 302.640045
current_received_ts = 302.639557
current_seq = 10867
count = 36
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 302.468994/10857, current 302.640045/10867: elapsed=171041.0us expected=166402.5us +- 832.0us, error 2.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 302.468994/10857, current 302.640045/10867: elapsed=171041.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 302.640045
last_received_ts = 302.639557
last_seq = 10867
current_ts = 302.811096
current_received_ts = 302.810577
current_seq = 10877
count = 37
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 302.640045/10867, current 302.811096/10877: elapsed=171036.0us expected=166402.5us +- 832.0us, error 2.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 302.640045/10867, current 302.811096/10877: elapsed=171036.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 302.811096
last_received_ts = 302.810577
last_seq = 10877
current_ts = 302.982117
current_received_ts = 302.981628
current_seq = 10887
count = 38
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 302.811096/10877, current 302.982117/10887: elapsed=171045.0us expected=166402.5us +- 832.0us, error 2.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 302.811096/10877, current 302.982117/10887: elapsed=171045.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 302.982117
last_received_ts = 302.981628
last_seq = 10887
current_ts = 303.152954
current_received_ts = 303.152435
current_seq = 10897
count = 39
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 302.982117/10887, current 303.152954/10897: elapsed=170830.0us expected=166402.5us +- 832.0us, error 2.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 302.982117/10887, current 303.152954/10897: elapsed=170830.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 303.152954
last_received_ts = 303.152435
last_seq = 10897
current_ts = 303.323425
current_received_ts = 303.322937
current_seq = 10907
count = 40
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 303.152954/10897, current 303.323425/10907: elapsed=170471.0us expected=166402.5us +- 832.0us, error 2.4%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 303.152954/10897, current 303.323425/10907: elapsed=170471.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 303.323425
last_received_ts = 303.322937
last_seq = 10907
current_ts = 303.493896
current_received_ts = 303.493408
current_seq = 10917
count = 41
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 303.323425/10907, current 303.493896/10917: elapsed=170461.0us expected=166402.5us +- 832.0us, error 2.4%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 303.323425/10907, current 303.493896/10917: elapsed=170461.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 303.493896
last_received_ts = 303.493408
last_seq = 10917
current_ts = 303.664337
current_received_ts = 303.663849
current_seq = 10927
count = 42
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 303.493896/10917, current 303.664337/10927: elapsed=170456.0us expected=166402.5us +- 832.0us, error 2.4%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 303.493896/10917, current 303.664337/10927: elapsed=170456.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 303.664337
last_received_ts = 303.663849
last_seq = 10927
current_ts = 303.834808
current_received_ts = 303.834290
current_seq = 10937
count = 43
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 303.664337/10927, current 303.834808/10937: elapsed=170451.0us expected=166402.5us +- 832.0us, error 2.4%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 303.664337/10927, current 303.834808/10937: elapsed=170451.0us expected=166402.5us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 303.834808
last_received_ts = 303.834290
last_seq = 10937
current_ts = 304.005280
current_received_ts = 304.004791
current_seq = 10947
count = 44
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 303.834808/10937, current 304.005280/10947: elapsed=170473.0us expected=166402.5us +- 832.0us, error 2.4%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 303.834808/10937, current 304.005280/10947: elapsed=170473.0us expected=166402.5us
(kms_flip:2889) INFO: Event vblank: expected 459, counted 450, passrate = 35.56%, encoder type 2
(kms_flip:2889) DEBUG: dropped frames, expected 459, counted 450, passrate = 35.56%, encoder type 2
(kms_flip:2889) DEBUG: Retrying without a hotplug event
(kms_flip:2889) DEBUG: No stale events found
(kms_flip:2889) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2889) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2889) INFO: Expected frametime: 16667us; measured 16878.2us +- 6.327us accuracy 0.11%
(kms_flip:2889) INFO: vblank interval differs from modeline! expected 16666.7us, measured 16878us +- 6.327us, difference 211.5us (33.4 sigma)
(kms_flip:2889) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 307.663910
current_received_ts = 307.663422
current_seq = 11160
count = 0
seq_step = 10
(kms_flip:2889) DEBUG: name = vblank
last_ts = 307.663910
last_received_ts = 307.663422
last_seq = 11160
current_ts = 307.832703
current_received_ts = 307.832184
current_seq = 11170
count = 1
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 307.663910/11160, current 307.832703/11170: elapsed=168787.0us expected=168781.9us +- 843.9us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 307.832703
last_received_ts = 307.832184
last_seq = 11170
current_ts = 308.001495
current_received_ts = 308.001068
current_seq = 11180
count = 2
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 307.832703/11170, current 308.001495/11180: elapsed=168786.0us expected=168781.9us +- 843.9us, error 0.0%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 308.001495
last_received_ts = 308.001068
last_seq = 11180
current_ts = 308.170135
current_received_ts = 308.169586
current_seq = 11190
count = 3
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 308.001495/11180, current 308.170135/11190: elapsed=168642.0us expected=168781.9us +- 843.9us, error 0.1%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 308.170135
last_received_ts = 308.169586
last_seq = 11190
current_ts = 308.338623
current_received_ts = 308.338104
current_seq = 11200
count = 4
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 308.170135/11190, current 308.338623/11200: elapsed=168502.0us expected=168781.9us +- 843.9us, error 0.2%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 308.338623
last_received_ts = 308.338104
last_seq = 11200
current_ts = 308.507111
current_received_ts = 308.506622
current_seq = 11210
count = 5
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 308.338623/11200, current 308.507111/11210: elapsed=168482.0us expected=168781.9us +- 843.9us, error 0.2%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 308.507111
last_received_ts = 308.506622
last_seq = 11210
current_ts = 308.675598
current_received_ts = 308.675110
current_seq = 11220
count = 6
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 308.507111/11210, current 308.675598/11220: elapsed=168487.0us expected=168781.9us +- 843.9us, error 0.2%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 308.675598
last_received_ts = 308.675110
last_seq = 11220
current_ts = 308.844086
current_received_ts = 308.843597
current_seq = 11230
count = 7
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 308.675598/11220, current 308.844086/11230: elapsed=168493.0us expected=168781.9us +- 843.9us, error 0.2%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 308.844086
last_received_ts = 308.843597
last_seq = 11230
current_ts = 309.012573
current_received_ts = 309.011993
current_seq = 11240
count = 8
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 308.844086/11230, current 309.012573/11240: elapsed=168490.0us expected=168781.9us +- 843.9us, error 0.2%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 309.012573
last_received_ts = 309.011993
last_seq = 11240
current_ts = 309.180939
current_received_ts = 309.180389
current_seq = 11250
count = 9
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 309.012573/11240, current 309.180939/11250: elapsed=168350.0us expected=168781.9us +- 843.9us, error 0.3%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 309.180939
last_received_ts = 309.180389
last_seq = 11250
current_ts = 309.349152
current_received_ts = 309.348663
current_seq = 11260
count = 10
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 309.180939/11250, current 309.349152/11260: elapsed=168228.0us expected=168781.9us +- 843.9us, error 0.3%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 309.349152
last_received_ts = 309.348663
last_seq = 11260
current_ts = 309.517395
current_received_ts = 309.516907
current_seq = 11270
count = 11
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 309.349152/11260, current 309.517395/11270: elapsed=168240.0us expected=168781.9us +- 843.9us, error 0.3%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 309.517395
last_received_ts = 309.516907
last_seq = 11270
current_ts = 309.685608
current_received_ts = 309.685150
current_seq = 11280
count = 12
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 309.517395/11270, current 309.685608/11280: elapsed=168218.0us expected=168781.9us +- 843.9us, error 0.3%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 309.685608
last_received_ts = 309.685150
last_seq = 11280
current_ts = 309.853851
current_received_ts = 309.853363
current_seq = 11290
count = 13
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 309.685608/11280, current 309.853851/11290: elapsed=168238.0us expected=168781.9us +- 843.9us, error 0.3%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 309.853851
last_received_ts = 309.853363
last_seq = 11290
current_ts = 310.022095
current_received_ts = 310.021576
current_seq = 11300
count = 14
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 309.853851/11290, current 310.022095/11300: elapsed=168232.0us expected=168781.9us +- 843.9us, error 0.3%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 310.022095
last_received_ts = 310.021576
last_seq = 11300
current_ts = 310.190186
current_received_ts = 310.189697
current_seq = 11310
count = 15
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 310.022095/11300, current 310.190186/11310: elapsed=168094.0us expected=168781.9us +- 843.9us, error 0.4%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 310.190186
last_received_ts = 310.189697
last_seq = 11310
current_ts = 310.358185
current_received_ts = 310.357666
current_seq = 11320
count = 16
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 310.190186/11310, current 310.358185/11320: elapsed=168004.0us expected=168781.9us +- 843.9us, error 0.5%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 310.358185
last_received_ts = 310.357666
last_seq = 11320
current_ts = 310.526184
current_received_ts = 310.525696
current_seq = 11330
count = 17
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 310.358185/11320, current 310.526184/11330: elapsed=168004.0us expected=168781.9us +- 843.9us, error 0.5%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 310.526184
last_received_ts = 310.525696
last_seq = 11330
current_ts = 310.694183
current_received_ts = 310.693695
current_seq = 11340
count = 18
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 310.526184/11330, current 310.694183/11340: elapsed=168005.0us expected=168781.9us +- 843.9us, error 0.5%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 310.694183
last_received_ts = 310.693695
last_seq = 11340
current_ts = 310.862183
current_received_ts = 310.861664
current_seq = 11350
count = 19
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 310.694183/11340, current 310.862183/11350: elapsed=167994.0us expected=168781.9us +- 843.9us, error 0.5%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 310.862183
last_received_ts = 310.861664
last_seq = 11350
current_ts = 311.030182
current_received_ts = 311.029694
current_seq = 11360
count = 20
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 310.862183/11350, current 311.030182/11360: elapsed=168010.0us expected=168781.9us +- 843.9us, error 0.5%
(kms_flip:2889) DEBUG: name = vblank
last_ts = 311.030182
last_received_ts = 311.029694
last_seq = 11360
current_ts = 311.198059
current_received_ts = 311.197601
current_seq = 11370
count = 21
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 311.030182/11360, current 311.198059/11370: elapsed=167879.0us expected=168781.9us +- 843.9us, error 0.5%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 311.030182/11360, current 311.198059/11370: elapsed=167879.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 311.198059
last_received_ts = 311.197601
last_seq = 11370
current_ts = 311.365875
current_received_ts = 311.365356
current_seq = 11380
count = 22
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 311.198059/11370, current 311.365875/11380: elapsed=167807.0us expected=168781.9us +- 843.9us, error 0.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 311.198059/11370, current 311.365875/11380: elapsed=167807.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 311.365875
last_received_ts = 311.365356
last_seq = 11380
current_ts = 311.533691
current_received_ts = 311.533142
current_seq = 11390
count = 23
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 311.365875/11380, current 311.533691/11390: elapsed=167798.0us expected=168781.9us +- 843.9us, error 0.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 311.365875/11380, current 311.533691/11390: elapsed=167798.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 311.533691
last_received_ts = 311.533142
last_seq = 11390
current_ts = 311.701477
current_received_ts = 311.700989
current_seq = 11400
count = 24
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 311.533691/11390, current 311.701477/11400: elapsed=167808.0us expected=168781.9us +- 843.9us, error 0.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 311.533691/11390, current 311.701477/11400: elapsed=167808.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 311.701477
last_received_ts = 311.700989
last_seq = 11400
current_ts = 311.869263
current_received_ts = 311.868774
current_seq = 11410
count = 25
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 311.701477/11400, current 311.869263/11410: elapsed=167791.0us expected=168781.9us +- 843.9us, error 0.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 311.701477/11400, current 311.869263/11410: elapsed=167791.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 311.869263
last_received_ts = 311.868774
last_seq = 11410
current_ts = 312.037079
current_received_ts = 312.036560
current_seq = 11420
count = 26
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 311.869263/11410, current 312.037079/11420: elapsed=167816.0us expected=168781.9us +- 843.9us, error 0.6%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 311.869263/11410, current 312.037079/11420: elapsed=167816.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 312.037079
last_received_ts = 312.036560
last_seq = 11420
current_ts = 312.204773
current_received_ts = 312.204254
current_seq = 11430
count = 27
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 312.037079/11420, current 312.204773/11430: elapsed=167681.0us expected=168781.9us +- 843.9us, error 0.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 312.037079/11420, current 312.204773/11430: elapsed=167681.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 312.204773
last_received_ts = 312.204254
last_seq = 11430
current_ts = 312.372406
current_received_ts = 312.371918
current_seq = 11440
count = 28
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 312.204773/11430, current 312.372406/11440: elapsed=167633.0us expected=168781.9us +- 843.9us, error 0.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 312.204773/11430, current 312.372406/11440: elapsed=167633.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 312.372406
last_received_ts = 312.371918
last_seq = 11440
current_ts = 312.540039
current_received_ts = 312.539520
current_seq = 11450
count = 29
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 312.372406/11440, current 312.540039/11450: elapsed=167631.0us expected=168781.9us +- 843.9us, error 0.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 312.372406/11440, current 312.540039/11450: elapsed=167631.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 312.540039
last_received_ts = 312.539520
last_seq = 11450
current_ts = 312.707672
current_received_ts = 312.707123
current_seq = 11460
count = 30
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 312.540039/11450, current 312.707672/11460: elapsed=167624.0us expected=168781.9us +- 843.9us, error 0.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 312.540039/11450, current 312.707672/11460: elapsed=167624.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 312.707672
last_received_ts = 312.707123
last_seq = 11460
current_ts = 312.875305
current_received_ts = 312.874756
current_seq = 11470
count = 31
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 312.707672/11460, current 312.875305/11470: elapsed=167637.0us expected=168781.9us +- 843.9us, error 0.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 312.707672/11460, current 312.875305/11470: elapsed=167637.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 312.875305
last_received_ts = 312.874756
last_seq = 11470
current_ts = 313.042938
current_received_ts = 313.042450
current_seq = 11480
count = 32
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 312.875305/11470, current 313.042938/11480: elapsed=167631.0us expected=168781.9us +- 843.9us, error 0.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 312.875305/11470, current 313.042938/11480: elapsed=167631.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 313.042938
last_received_ts = 313.042450
last_seq = 11480
current_ts = 313.210449
current_received_ts = 313.209930
current_seq = 11490
count = 33
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 313.042938/11480, current 313.210449/11490: elapsed=167525.0us expected=168781.9us +- 843.9us, error 0.7%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 313.042938/11480, current 313.210449/11490: elapsed=167525.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 313.210449
last_received_ts = 313.209930
last_seq = 11490
current_ts = 313.377930
current_received_ts = 313.377441
current_seq = 11500
count = 34
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 313.210449/11490, current 313.377930/11500: elapsed=167473.0us expected=168781.9us +- 843.9us, error 0.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 313.210449/11490, current 313.377930/11500: elapsed=167473.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 313.377930
last_received_ts = 313.377441
last_seq = 11500
current_ts = 313.545410
current_received_ts = 313.544922
current_seq = 11510
count = 35
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 313.377930/11500, current 313.545410/11510: elapsed=167471.0us expected=168781.9us +- 843.9us, error 0.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 313.377930/11500, current 313.545410/11510: elapsed=167471.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 313.545410
last_received_ts = 313.544922
last_seq = 11510
current_ts = 313.712891
current_received_ts = 313.712341
current_seq = 11520
count = 36
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 313.545410/11510, current 313.712891/11520: elapsed=167487.0us expected=168781.9us +- 843.9us, error 0.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 313.545410/11510, current 313.712891/11520: elapsed=167487.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 313.712891
last_received_ts = 313.712341
last_seq = 11520
current_ts = 313.880371
current_received_ts = 313.879822
current_seq = 11530
count = 37
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 313.712891/11520, current 313.880371/11530: elapsed=167477.0us expected=168781.9us +- 843.9us, error 0.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 313.712891/11520, current 313.880371/11530: elapsed=167477.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 313.880371
last_received_ts = 313.879822
last_seq = 11530
current_ts = 314.047852
current_received_ts = 314.047363
current_seq = 11540
count = 38
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 313.880371/11530, current 314.047852/11540: elapsed=167481.0us expected=168781.9us +- 843.9us, error 0.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 313.880371/11530, current 314.047852/11540: elapsed=167481.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 314.047852
last_received_ts = 314.047363
last_seq = 11540
current_ts = 314.215210
current_received_ts = 314.214722
current_seq = 11550
count = 39
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 314.047852/11540, current 314.215210/11550: elapsed=167370.0us expected=168781.9us +- 843.9us, error 0.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 314.047852/11540, current 314.215210/11550: elapsed=167370.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 314.215210
last_received_ts = 314.214722
last_seq = 11550
current_ts = 314.382568
current_received_ts = 314.381989
current_seq = 11560
count = 40
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 314.215210/11550, current 314.382568/11560: elapsed=167347.0us expected=168781.9us +- 843.9us, error 0.9%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 314.215210/11550, current 314.382568/11560: elapsed=167347.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 314.382568
last_received_ts = 314.381989
last_seq = 11560
current_ts = 314.549927
current_received_ts = 314.549438
current_seq = 11570
count = 41
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 314.382568/11560, current 314.549927/11570: elapsed=167355.0us expected=168781.9us +- 843.9us, error 0.8%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 314.382568/11560, current 314.549927/11570: elapsed=167355.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 314.549927
last_received_ts = 314.549438
last_seq = 11570
current_ts = 314.717255
current_received_ts = 314.716736
current_seq = 11580
count = 42
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 314.549927/11570, current 314.717255/11580: elapsed=167341.0us expected=168781.9us +- 843.9us, error 0.9%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 314.549927/11570, current 314.717255/11580: elapsed=167341.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 314.717255
last_received_ts = 314.716736
last_seq = 11580
current_ts = 314.884613
current_received_ts = 314.884033
current_seq = 11590
count = 43
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 314.717255/11580, current 314.884613/11590: elapsed=167345.0us expected=168781.9us +- 843.9us, error 0.9%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 314.717255/11580, current 314.884613/11590: elapsed=167345.0us expected=168781.9us
(kms_flip:2889) DEBUG: name = vblank
last_ts = 314.884613
last_received_ts = 314.884033
last_seq = 11590
current_ts = 315.051941
current_received_ts = 315.051483
current_seq = 11600
count = 44
seq_step = 10
(kms_flip:2889) DEBUG: vblank ts/seq: last 314.884613/11590, current 315.051941/11600: elapsed=167346.0us expected=168781.9us +- 843.9us, error 0.9%
(kms_flip:2889) DEBUG: inconsistent vblank ts/seq: last 314.884613/11590, current 315.051941/11600: elapsed=167346.0us expected=168781.9us
(kms_flip:2889) INFO: Event vblank: expected 447, counted 450, passrate = 46.67%, encoder type 2
(kms_flip:2889) DEBUG: dropped frames, expected 447, counted 450, passrate = 46.67%, encoder type 2
(kms_flip:2889) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1707:
(kms_flip:2889) CRITICAL: Failed assertion: !retried
(kms_flip:2889) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2889) igt_core-INFO: Stack trace:
(kms_flip:2889) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2889) igt_core-INFO:   #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
(kms_flip:2889) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:2889) igt_core-INFO:   #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
(kms_flip:2889) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:2889) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2889) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2889) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A1: FAIL (18.965s)
Dmesg
<6> [295.393637] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1
<7> [295.394254] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:89]
<7> [295.394481] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:90]
<7> [295.430656] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:52:pipe A]
<7> [295.430835] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:71:pipe B]
<7> [295.430921] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [295.431248] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [295.431620] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [295.432010] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in has_pch_encoder (expected yes, found no)
<7> [295.432377] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in fdi_lanes (expected 1, found 0)
<7> [295.432726] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0)
<7> [295.433113] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in output_types (expected 0x00000002, found 0x00000000)
<7> [295.433494] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [295.433842] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1024, found 0)
<7> [295.434225] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 1344, found 0)
<7> [295.434583] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1024, found 0)
<7> [295.434939] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 1344, found 0)
<7> [295.435356] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 1048, found 0)
<7> [295.435728] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 1184, found 0)
<7> [295.436119] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 768, found 0)
<7> [295.436483] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 768, found 0)
<7> [295.436839] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 771, found 0)
<7> [295.437231] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 777, found 0)
<7> [295.437597] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 806, found 0)
<7> [295.437974] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 806, found 0)
<7> [295.438336] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1024, found 0)
<7> [295.438683] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 1344, found 0)
<7> [295.439167] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1024, found 0)
<7> [295.439516] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 1344, found 0)
<7> [295.439863] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 1048, found 0)
<7> [295.440258] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 1184, found 0)
<7> [295.440625] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 768, found 0)
<7> [295.441009] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 768, found 0)
<7> [295.441405] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 771, found 0)
<7> [295.441751] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 777, found 0)
<7> [295.442136] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 806, found 0)
<7> [295.442512] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 806, found 0)
<7> [295.442869] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [295.443258] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [295.443617] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [295.443988] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [295.444344] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 64800, found 0)
<7> [295.444702] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 64800, found 0)
<7> [295.445086] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in port_clock (expected 64800, found 0)
<7> [295.445445] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:71:pipe B] fastset requirement not met, forcing full modeset
<7> [295.445803] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:71:pipe B] releasing PCH DPLL A
<7> [295.446249] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:71:pipe B] min cdclk: 72000 kHz -> 0 kHz
<7> [295.446612] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:71:pipe B] enable: no [modeset]
<7> [295.446988] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:primary B] fb: [NOFB], visible: no
<7> [295.447526] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B
<7> [295.458608] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found
<7> [295.458844] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found
<7> [295.459104] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found
<7> [295.474253] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x2, on? 1) for [CRTC:71:pipe B]
<7> [295.474762] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A
<7> [295.475533] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:73:CRT]
<7> [295.476290] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:HDMI D]
<7> [295.477040] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:82:DP D]
<7> [295.477754] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:72:VGA-1]
<7> [295.478352] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:71:pipe B]
<7> [295.478815] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:52:pipe A]
<7> [295.478856] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:75:HDMI-A-1]
<7> [295.479055] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36)
<7> [295.479436] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [295.479787] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3
<7> [295.480104] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [295.480363] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [295.480687] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [295.481073] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes)
<7> [295.481437] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3)
<7> [295.481771] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288)
<7> [295.482063] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [295.482339] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [295.482572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [295.482806] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [295.483060] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [295.483347] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [295.483615] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [295.483847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [295.484106] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [295.484386] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [295.484619] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [295.484852] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [295.485101] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [295.485374] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [295.485607] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [295.485840] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [295.486111] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [295.486402] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [295.486628] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [295.486868] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [295.487134] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [295.487403] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [295.487643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [295.487875] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [295.488208] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [295.488475] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [295.488709] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [295.488999] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [295.489245] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [295.489506] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [295.489746] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes)
<7> [295.490013] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_infoframe (expected no, found yes)
<7> [295.490288] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in dpll_hw_state
<7> [295.490523] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [295.490755] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09
<7> [295.491044] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [295.491314] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06
<7> [295.491540] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [295.491767] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800)
<7> [295.492049] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800)
<7> [295.492336] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in port_clock (expected 0, found 223200)
<7> [295.492570] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)
<7> [295.492803] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)
<7> [295.493074] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in avi infoframe
<7> [295.493351] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [295.493611] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [295.493844] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [295.493847] i915 0000:00:02.0: colorspace: RGB
<7> [295.493849] i915 0000:00:02.0: scan mode: Underscan
<7> [295.493851] i915 0000:00:02.0: colorimetry: No Data
<7> [295.493853] i915 0000:00:02.0: picture aspect: 16:9
<7> [295.493855] i915 0000:00:02.0: active aspect: Same as Picture
<7> [295.493857] i915 0000:00:02.0: itc: No Data
<7> [295.493859] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [295.493861] i915 0000:00:02.0: quantization range: Default
<7> [295.493863] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [295.493865] i915 0000:00:02.0: video code: 16
<7> [295.493867] i915 0000:00:02.0: ycc quantization range: Full
<7> [295.493869] i915 0000:00:02.0: hdmi content type: Graphics
<7> [295.493871] i915 0000:00:02.0: pixel repeat: 0
<7> [295.493873] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [295.493876] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in spd infoframe
<7> [295.494128] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [295.494420] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [295.494653] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [295.494656] i915 0000:00:02.0: vendor: Intel
<7> [295.494658] i915 0000:00:02.0: product: Integrated gfx
<7> [295.494660] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [295.494663] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hdmi infoframe
<7> [295.494895] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [295.495164] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [295.495405] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [295.495408] i915 0000:00:02.0: empty frame
<7> [295.495411] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] fastset requirement not met, forcing full modeset
<7> [295.495676] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:52:pipe A] min cdclk: 0 kHz -> 165334 kHz
<7> [295.495910] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:52:pipe A] allocated PCH DPLL A
<7> [295.496169] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:52:pipe A] reserving PCH DPLL A
<7> [295.496193] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on
<7> [295.496411] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:52:pipe A] enable: yes [modeset]
<7> [295.496637] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [295.496863] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0
<7> [295.497117] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [295.497370] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [295.497605] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [295.497837] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [295.498111] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64
<7> [295.498357] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71
<7> [295.498592] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6
<7> [295.498823] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [295.498826] i915 0000:00:02.0: colorspace: RGB
<7> [295.498828] i915 0000:00:02.0: scan mode: Underscan
<7> [295.498830] i915 0000:00:02.0: colorimetry: No Data
<7> [295.498832] i915 0000:00:02.0: picture aspect: 16:9
<7> [295.498834] i915 0000:00:02.0: active aspect: Same as Picture
<7> [295.498836] i915 0000:00:02.0: itc: No Data
<7> [295.498838] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [295.498840] i915 0000:00:02.0: quantization range: Default
<7> [295.498842] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [295.498844] i915 0000:00:02.0: video code: 16
<7> [295.498846] i915 0000:00:02.0: ycc quantization range: Full
<7> [295.498848] i915 0000:00:02.0: hdmi content type: Graphics
<7> [295.498849] i915 0000:00:02.0: pixel repeat: 0
<7> [295.498851] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [295.498854] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [295.498856] i915 0000:00:02.0: vendor: Intel
<7> [295.498858] i915 0000:00:02.0: product: Integrated gfx
<7> [295.498860] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [295.498862] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [295.498864] i915 0000:00:02.0: empty frame
<7> [295.498866] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 08 00 65 32 00 01 00 00 00 00 00 00 00 00
<7> [295.499136] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 4d 69 20 54 56 09 07 07 11 17 50 51
<7> [295.499374] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 07 00 00 00
<7> [295.499599] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1
<7> [295.499824] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [295.500077] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0
<7> [295.500323] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0
<7> [295.500557] 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> [295.500788] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [295.501069] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [295.501303] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [295.501537] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [295.501763] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [295.502015] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pipe src: 1920x1080+0+0, pixel rate 148800, min cdclk 165334
<7> [295.502261] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0
<7> [295.502511] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [295.502743] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [295.502986] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06
<7> [295.503219] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [295.503450] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [295.503681] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [295.503913] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [295.504160] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [295.504392] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [295.504623] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [295.504855] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:primary A] fb: [FB:89] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [295.505099] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [295.505331] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [295.507599] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on
<7> [295.507846] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:73:CRT]
<7> [295.508098] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:HDMI D]
<7> [295.508335] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:82:DP D]
<7> [295.509203] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [295.510298] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100
<7> [295.510550] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done.
<7> [295.511438] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x200
<7> [295.511667] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done.
<7> [295.511893] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done.
<7> [295.512136] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:52:pipe A]
<7> [295.512368] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A
<7> [295.580732] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:75:HDMI-A-1][ENCODER:74:HDMI D] Enable audio codec on [CRTC:52:pipe A], 36 bytes ELD
<7> [295.597292] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults
<7> [295.597657] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000)
<7> [295.598047] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:75:HDMI-A-1]
<7> [295.598424] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:52:pipe A]
<7> [306.328563] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:52:pipe A]
<7> [306.328782] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [306.329403] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [306.330187] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [306.331035] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_pch_encoder (expected yes, found no)
<7> [306.331850] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_lanes (expected 3, found 0)
<7> [306.332527] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_m_n (expected tu 64 data 6934582/8388608 link 288940/524288, found tu 0, data 0/0 link 0/0)
<7> [306.332887] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [306.333271] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [306.333630] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [306.333988] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [306.334374] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [306.334734] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [306.335091] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [306.335470] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [306.335830] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [306.336213] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [306.336580] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [306.336927] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [306.337302] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [306.337650] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [306.337997] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [306.338354] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [306.338704] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [306.339053] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [306.339449] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [306.339816] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [306.340201] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [306.340561] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [306.340908] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [306.341310] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [306.341675] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [306.342032] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [306.342434] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [306.342782] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [306.343166] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [306.343514] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [306.343874] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_hdmi_sink (expected yes, found no)
<7> [306.344260] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_infoframe (expected yes, found no)
<7> [306.344627] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0)
<7> [306.344984] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148800, found 0)
<7> [306.345401] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148800, found 0)
<7> [306.345768] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in port_clock (expected 223200, found 0)
<7> [306.346144] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000)
<7> [306.346492] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000)
<7> [306.346847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in avi infoframe
<7> [306.347230] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [306.347593] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [306.347598] i915 0000:00:02.0: colorspace: RGB
<7> [306.347602] i915 0000:00:02.0: scan mode: Underscan
<7> [306.347605] i915 0000:00:02.0: colorimetry: No Data
<7> [306.347609] i915 0000:00:02.0: picture aspect: 16:9
<7> [306.347613] i915 0000:00:02.0: active aspect: Same as Picture
<7> [306.347617] i915 0000:00:02.0: itc: No Data
<7> [306.347621] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [306.347625] i915 0000:00:02.0: quantization range: Default
<7> [306.347629] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [306.347633] i915 0000:00:02.0: video code: 16
<7> [306.347637] i915 0000:00:02.0: ycc quantization range: Full
<7> [306.347641] i915 0000:00:02.0: hdmi content type: Graphics
<7> [306.347645] i915 0000:00:02.0: pixel repeat: 0
<7> [306.347649] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [306.347654] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [306.348045] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in spd infoframe
<7> [306.348395] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [306.348753] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [306.348758] i915 0000:00:02.0: vendor: Intel
<7> [306.348762] i915 0000:00:02.0: product: Integrated gfx
<7> [306.348766] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [306.348770] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [306.349146] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hdmi infoframe
<7> [306.349495] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [306.349841] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [306.349846] i915 0000:00:02.0: empty frame
<7> [306.349850] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [306.350259] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] fastset requirement not met, forcing full modeset
<7> [306.350616] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:52:pipe A] releasing PCH DPLL A
<7> [306.351062] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:52:pipe A] min cdclk: 165334 kHz -> 0 kHz
<7> [306.351425] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:52:pipe A] enable: no [modeset]
<7> [306.351782] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:primary A] fb: [NOFB], visible: no
<7> [306.352208] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:75:HDMI-A-1][ENCODER:74:HDMI D] Disable audio codec on [CRTC:52:pipe A]
<7> [306.375776] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [306.394227] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found
<7> [306.394704] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found
<7> [306.395188] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found
<7> [306.404395] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x1, on? 1) for [CRTC:52:pipe A]
<7> [306.404904] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A
<7> [306.405690] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:73:CRT]
<7> [306.406239] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:HDMI D]
<7> [306.406738] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:82:DP D]
<7> [306.407313] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:75:HDMI-A-1]
<7> [306.407614] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:52:pipe A]
<7> [306.408045] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:71:pipe B]
<7> [306.408199] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:52:pipe A]
<7> [306.408227] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:75:HDMI-A-1]
<7> [306.408317] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36)
<7> [306.408581] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [306.408811] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3
<7> [306.409080] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [306.409369] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [306.409620] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [306.409848] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes)
<7> [306.410122] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3)
<7> [306.410382] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288)
<7> [306.410643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [306.410893] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [306.411208] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [306.411468] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [306.411695] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [306.411958] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [306.412252] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [306.412513] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [306.412762] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [306.413027] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [306.413299] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [306.413541] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [306.413788] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [306.414090] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [306.414339] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [306.414571] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [306.414804] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [306.415073] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [306.415331] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [306.415593] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [306.415884] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [306.416132] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [306.416365] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [306.416602] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [306.416870] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [306.417151] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [306.417385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [306.417618] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [306.417883] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [306.418145] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [306.418391] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes)
<7> [306.418654] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_infoframe (expected no, found yes)
<7> [306.418983] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [306.419221] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800)
<7> [306.419447] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800)
<7> [306.419696] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in port_clock (expected 0, found 223200)
<7> [306.419970] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)
<7> [306.420247] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)
<7> [306.420489] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in avi infoframe
<7> [306.420721] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [306.420988] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [306.421266] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [306.421269] i915 0000:00:02.0: colorspace: RGB
<7> [306.421271] i915 0000:00:02.0: scan mode: Underscan
<7> [306.421273] i915 0000:00:02.0: colorimetry: No Data
<7> [306.421275] i915 0000:00:02.0: picture aspect: 16:9
<7> [306.421277] i915 0000:00:02.0: active aspect: Same as Picture
<7> [306.421279] i915 0000:00:02.0: itc: No Data
<7> [306.421281] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [306.421283] i915 0000:00:02.0: quantization range: Default
<7> [306.421285] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [306.421287] i915 0000:00:02.0: video code: 16
<7> [306.421289] i915 0000:00:02.0: ycc quantization range: Full
<7> [306.421291] i915 0000:00:02.0: hdmi content type: Graphics
<7> [306.421293] i915 0000:00:02.0: pixel repeat: 0
<7> [306.421295] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [306.421298] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in spd infoframe
<7> [306.421544] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [306.421847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [306.422123] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [306.422125] i915 0000:00:02.0: vendor: Intel
<7> [306.422128] i915 0000:00:02.0: product: Integrated gfx
<7> [306.422130] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [306.422132] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hdmi infoframe
<7> [306.422359] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [306.422584] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [306.422852] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [306.422857] i915 0000:00:02.0: empty frame
<7> [306.422861] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] fastset requirement not met, forcing full modeset
<7> [306.423198] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:52:pipe A] min cdclk: 0 kHz -> 165334 kHz
<7> [306.423460] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:52:pipe A] allocated PCH DPLL A
<7> [306.423761] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:52:pipe A] reserving PCH DPLL A
<7> [306.424020] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:52:pipe A] enable: yes [modeset]
<7> [306.424247] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [306.424473] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0
<7> [306.424756] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [306.425047] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [306.425296] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [306.425521] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [306.425802] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64
<7> [306.425812] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on
<7> [306.426075] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71
<7> [306.426327] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6
<7> [306.426591] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [306.426594] i915 0000:00:02.0: colorspace: RGB
<7> [306.426596] i915 0000:00:02.0: scan mode: Underscan
<7> [306.426598] i915 0000:00:02.0: colorimetry: No Data
<7> [306.426601] i915 0000:00:02.0: picture aspect: 16:9
<7> [306.426603] i915 0000:00:02.0: active aspect: Same as Picture
<7> [306.426605] i915 0000:00:02.0: itc: No Data
<7> [306.426607] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [306.426609] i915 0000:00:02.0: quantization range: Default
<7> [306.426610] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [306.426612] i915 0000:00:02.0: video code: 16
<7> [306.426614] i915 0000:00:02.0: ycc quantization range: Full
<7> [306.426616] i915 0000:00:02.0: hdmi content type: Graphics
<7> [306.426618] i915 0000:00:02.0: pixel repeat: 0
<7> [306.426620] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [306.426623] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [306.426625] i915 0000:00:02.0: vendor: Intel
<7> [306.426627] i915 0000:00:02.0: product: Integrated gfx
<7> [306.426629] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [306.426631] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [306.426633] i915 0000:00:02.0: empty frame
<7> [306.426635] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 08 00 65 32 00 01 00 00 00 00 00 00 00 00
<7> [306.426939] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 4d 69 20 54 56 09 07 07 11 17 50 51
<7> [306.427175] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 07 00 00 00
<7> [306.427401] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1
<7> [306.427625] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [306.427935] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0
<7> [306.428226] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0
<7> [306.428501] 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> [306.428773] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [306.429014] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [306.429241] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [306.429496] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [306.429779] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [306.430059] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pipe src: 1920x1080+0+0, pixel rate 148800, min cdclk 165334
<7> [306.430293] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0
<7> [306.430525] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [306.430777] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [306.431046] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06
<7> [306.431293] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [306.431551] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [306.431821] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [306.432068] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [306.432300] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [306.432543] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [306.432819] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [306.433105] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:primary A] fb: [FB:89] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [306.433340] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [306.433617] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [306.433913] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on
<7> [306.434170] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:73:CRT]
<7> [306.434433] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:HDMI D]
<7> [306.434686] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:82:DP D]
<7> [306.435569] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [306.436715] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100
<7> [306.436973] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done.
<7> [306.437892] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x200
<7> [306.438133] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done.
<7> [306.438391] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done.
<7> [306.438681] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:52:pipe A]
<7> [306.438927] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A
<7> [306.490658] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:75:HDMI-A-1][ENCODER:74:HDMI D] Enable audio codec on [CRTC:52:pipe A], 36 bytes ELD
<7> [306.507258] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults
<7> [306.507839] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000)
<7> [306.508356] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:75:HDMI-A-1]
<7> [306.508980] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:52:pipe A]
<6> [314.360062] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL
Created at 2026-03-10 17:38:11