Results for igt@kms_flip@wf_vblank-ts-check@a-hdmi-a2

Result: Fail

integration-manifest git-log-oneline i915_display_info6 igt_runner6 runtimes6 results6.json results6-i915-load.json i915_display_info_post_exec6 boot6 dmesg6

DetailValue
Duration 24.27 seconds
Hostname 
shard-rkl-4
Igt-Version 
IGT-Version: 2.2-g005281c52 (x86_64) (Linux: 6.18.0-rc7-CI_DRM_17608-g157d0854a24f+ x86_64)
Out 
Using IGT_SRANDOM=1764371069 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: wf_vblank-ts-check
Starting dynamic subtest: A-HDMI-A2
  1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 
Expected frametime: 18974us; measured 18974.3us +- 9.279us accuracy 0.15%
Event vblank: expected 527, counted 530, passrate = 66.04%, encoder type 2
Expected frametime: 18974us; measured 18814.9us +- 5.994us accuracy 0.10%
vblank interval differs from modeline! expected 18973.8us, measured 18815us +- 5.994us, difference 158.8us (26.5 sigma)
Event vblank: expected 532, counted 530, passrate = 62.26%, 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:1889 run_test()
  #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
  #4 ../tests/kms_flip.c:2045 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A2: FAIL (24.267s)
Err 
Starting subtest: wf_vblank-ts-check
Starting dynamic subtest: A-HDMI-A2
(kms_flip:2044) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1709:
(kms_flip:2044) CRITICAL: Failed assertion: !retried
Dynamic subtest A-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2044) DEBUG: vblank ts/seq: last 60.984009/436, current 61.173748/446: elapsed=189741.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 61.173748
last_received_ts = 61.173531
last_seq = 446
current_ts = 61.363487
current_received_ts = 61.363266
current_seq = 456
count = 8
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 61.173748/446, current 61.363487/456: elapsed=189738.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 61.363487
last_received_ts = 61.363266
last_seq = 456
current_ts = 61.553226
current_received_ts = 61.552902
current_seq = 466
count = 9
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 61.363487/456, current 61.553226/466: elapsed=189740.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 61.553226
last_received_ts = 61.552902
last_seq = 466
current_ts = 61.742966
current_received_ts = 61.742470
current_seq = 476
count = 10
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 61.553226/466, current 61.742966/476: elapsed=189740.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 61.742966
last_received_ts = 61.742470
last_seq = 476
current_ts = 61.932701
current_received_ts = 61.932236
current_seq = 486
count = 11
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 61.742966/476, current 61.932701/486: elapsed=189737.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 61.932701
last_received_ts = 61.932236
last_seq = 486
current_ts = 62.122437
current_received_ts = 62.122215
current_seq = 496
count = 12
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 61.932701/486, current 62.122437/496: elapsed=189732.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 62.122437
last_received_ts = 62.122215
last_seq = 496
current_ts = 62.312176
current_received_ts = 62.311649
current_seq = 506
count = 13
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 62.122437/496, current 62.312176/506: elapsed=189742.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 62.312176
last_received_ts = 62.311649
last_seq = 506
current_ts = 62.501907
current_received_ts = 62.501553
current_seq = 516
count = 14
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 62.312176/506, current 62.501907/516: elapsed=189731.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 62.501907
last_received_ts = 62.501553
last_seq = 516
current_ts = 62.691647
current_received_ts = 62.691425
current_seq = 526
count = 15
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 62.501907/516, current 62.691647/526: elapsed=189740.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 62.691647
last_received_ts = 62.691425
last_seq = 526
current_ts = 62.881390
current_received_ts = 62.881168
current_seq = 536
count = 16
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 62.691647/526, current 62.881390/536: elapsed=189740.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 62.881390
last_received_ts = 62.881168
last_seq = 536
current_ts = 63.071114
current_received_ts = 63.070911
current_seq = 546
count = 17
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 62.881390/536, current 63.071114/546: elapsed=189727.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 63.071114
last_received_ts = 63.070911
last_seq = 546
current_ts = 63.260857
current_received_ts = 63.260548
current_seq = 556
count = 18
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 63.071114/546, current 63.260857/556: elapsed=189742.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 63.260857
last_received_ts = 63.260548
last_seq = 556
current_ts = 63.450596
current_received_ts = 63.450184
current_seq = 566
count = 19
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 63.260857/556, current 63.450596/566: elapsed=189739.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 63.450596
last_received_ts = 63.450184
last_seq = 566
current_ts = 63.640339
current_received_ts = 63.640125
current_seq = 576
count = 20
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 63.450596/566, current 63.640339/576: elapsed=189744.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 63.640339
last_received_ts = 63.640125
last_seq = 576
current_ts = 63.830067
current_received_ts = 63.829865
current_seq = 586
count = 21
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 63.640339/576, current 63.830067/586: elapsed=189728.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 63.830067
last_received_ts = 63.829865
last_seq = 586
current_ts = 64.019814
current_received_ts = 64.019295
current_seq = 596
count = 22
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 63.830067/586, current 64.019814/596: elapsed=189747.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 64.019814
last_received_ts = 64.019295
last_seq = 596
current_ts = 64.209549
current_received_ts = 64.209190
current_seq = 606
count = 23
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 64.019814/596, current 64.209549/606: elapsed=189731.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 64.209549
last_received_ts = 64.209190
last_seq = 606
current_ts = 64.399292
current_received_ts = 64.398964
current_seq = 616
count = 24
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 64.209549/606, current 64.399292/616: elapsed=189748.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 64.399292
last_received_ts = 64.398964
last_seq = 616
current_ts = 64.589035
current_received_ts = 64.588661
current_seq = 626
count = 25
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 64.399292/616, current 64.589035/626: elapsed=189738.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 64.589035
last_received_ts = 64.588661
last_seq = 626
current_ts = 64.778763
current_received_ts = 64.778542
current_seq = 636
count = 26
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 64.589035/626, current 64.778763/636: elapsed=189731.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 64.778763
last_received_ts = 64.778542
last_seq = 636
current_ts = 64.968491
current_received_ts = 64.968185
current_seq = 646
count = 27
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 64.778763/636, current 64.968491/646: elapsed=189729.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 64.968491
last_received_ts = 64.968185
last_seq = 646
current_ts = 65.158241
current_received_ts = 65.157837
current_seq = 656
count = 28
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 64.968491/646, current 65.158241/656: elapsed=189752.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 65.158241
last_received_ts = 65.157837
last_seq = 656
current_ts = 65.347969
current_received_ts = 65.347626
current_seq = 666
count = 29
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 65.158241/656, current 65.347969/666: elapsed=189724.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 65.347969
last_received_ts = 65.347626
last_seq = 666
current_ts = 65.537704
current_received_ts = 65.537239
current_seq = 676
count = 30
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 65.347969/666, current 65.537704/676: elapsed=189738.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 65.537704
last_received_ts = 65.537239
last_seq = 676
current_ts = 65.727455
current_received_ts = 65.726906
current_seq = 686
count = 31
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 65.537704/676, current 65.727455/686: elapsed=189746.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 65.727455
last_received_ts = 65.726906
last_seq = 686
current_ts = 65.917191
current_received_ts = 65.916840
current_seq = 696
count = 32
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 65.727455/686, current 65.917191/696: elapsed=189742.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 65.917191
last_received_ts = 65.916840
last_seq = 696
current_ts = 66.106926
current_received_ts = 66.106712
current_seq = 706
count = 33
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 65.917191/696, current 66.106926/706: elapsed=189735.0us expected=189743.1us +- 948.7us, error 0.0%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 66.106926
last_received_ts = 66.106712
last_seq = 706
current_ts = 66.295952
current_received_ts = 66.295631
current_seq = 716
count = 34
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 66.106926/706, current 66.295952/716: elapsed=189026.0us expected=189743.1us +- 948.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 66.295952
last_received_ts = 66.295631
last_seq = 716
current_ts = 66.482162
current_received_ts = 66.481934
current_seq = 726
count = 35
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 66.295952/716, current 66.482162/726: elapsed=186205.0us expected=189743.1us +- 948.7us, error 1.9%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 66.295952/716, current 66.482162/726: elapsed=186205.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 66.482162
last_received_ts = 66.481934
last_seq = 726
current_ts = 66.668358
current_received_ts = 66.667900
current_seq = 736
count = 36
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 66.482162/726, current 66.668358/736: elapsed=186198.0us expected=189743.1us +- 948.7us, error 1.9%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 66.482162/726, current 66.668358/736: elapsed=186198.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 66.668358
last_received_ts = 66.667900
last_seq = 736
current_ts = 66.854561
current_received_ts = 66.854347
current_seq = 746
count = 37
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 66.668358/736, current 66.854561/746: elapsed=186205.0us expected=189743.1us +- 948.7us, error 1.9%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 66.668358/736, current 66.854561/746: elapsed=186205.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 66.854561
last_received_ts = 66.854347
last_seq = 746
current_ts = 67.040771
current_received_ts = 67.040443
current_seq = 756
count = 38
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 66.854561/746, current 67.040771/756: elapsed=186208.0us expected=189743.1us +- 948.7us, error 1.9%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 66.854561/746, current 67.040771/756: elapsed=186208.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 67.040771
last_received_ts = 67.040443
last_seq = 756
current_ts = 67.226959
current_received_ts = 67.226646
current_seq = 766
count = 39
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 67.040771/756, current 67.226959/766: elapsed=186186.0us expected=189743.1us +- 948.7us, error 1.9%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 67.040771/756, current 67.226959/766: elapsed=186186.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 67.226959
last_received_ts = 67.226646
last_seq = 766
current_ts = 67.413528
current_received_ts = 67.413208
current_seq = 776
count = 40
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 67.226959/766, current 67.413528/776: elapsed=186572.0us expected=189743.1us +- 948.7us, error 1.7%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 67.226959/766, current 67.413528/776: elapsed=186572.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 67.413528
last_received_ts = 67.413208
last_seq = 776
current_ts = 67.600182
current_received_ts = 67.599960
current_seq = 786
count = 41
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 67.413528/776, current 67.600182/786: elapsed=186652.0us expected=189743.1us +- 948.7us, error 1.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 67.413528/776, current 67.600182/786: elapsed=186652.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 67.600182
last_received_ts = 67.599960
last_seq = 786
current_ts = 67.786812
current_received_ts = 67.786606
current_seq = 796
count = 42
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 67.600182/786, current 67.786812/796: elapsed=186634.0us expected=189743.1us +- 948.7us, error 1.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 67.600182/786, current 67.786812/796: elapsed=186634.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 67.786812
last_received_ts = 67.786606
last_seq = 796
current_ts = 67.973473
current_received_ts = 67.973114
current_seq = 806
count = 43
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 67.786812/796, current 67.973473/806: elapsed=186656.0us expected=189743.1us +- 948.7us, error 1.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 67.786812/796, current 67.973473/806: elapsed=186656.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 67.973473
last_received_ts = 67.973114
last_seq = 806
current_ts = 68.160110
current_received_ts = 68.159737
current_seq = 816
count = 44
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 67.973473/806, current 68.160110/816: elapsed=186637.0us expected=189743.1us +- 948.7us, error 1.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 67.973473/806, current 68.160110/816: elapsed=186637.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 68.160110
last_received_ts = 68.159737
last_seq = 816
current_ts = 68.346947
current_received_ts = 68.346596
current_seq = 826
count = 45
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 68.160110/816, current 68.346947/826: elapsed=186841.0us expected=189743.1us +- 948.7us, error 1.5%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 68.160110/816, current 68.346947/826: elapsed=186841.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 68.346947
last_received_ts = 68.346596
last_seq = 826
current_ts = 68.533974
current_received_ts = 68.533669
current_seq = 836
count = 46
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 68.346947/826, current 68.533974/836: elapsed=187024.0us expected=189743.1us +- 948.7us, error 1.4%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 68.346947/826, current 68.533974/836: elapsed=187024.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 68.533974
last_received_ts = 68.533669
last_seq = 836
current_ts = 68.721008
current_received_ts = 68.720604
current_seq = 846
count = 47
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 68.533974/836, current 68.721008/846: elapsed=187037.0us expected=189743.1us +- 948.7us, error 1.4%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 68.533974/836, current 68.721008/846: elapsed=187037.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 68.721008
last_received_ts = 68.720604
last_seq = 846
current_ts = 68.908035
current_received_ts = 68.907646
current_seq = 856
count = 48
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 68.721008/846, current 68.908035/856: elapsed=187026.0us expected=189743.1us +- 948.7us, error 1.4%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 68.721008/846, current 68.908035/856: elapsed=187026.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 68.908035
last_received_ts = 68.907646
last_seq = 856
current_ts = 69.095062
current_received_ts = 69.094841
current_seq = 866
count = 49
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 68.908035/856, current 69.095062/866: elapsed=187028.0us expected=189743.1us +- 948.7us, error 1.4%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 68.908035/856, current 69.095062/866: elapsed=187028.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 69.095062
last_received_ts = 69.094841
last_seq = 866
current_ts = 69.282120
current_received_ts = 69.281792
current_seq = 876
count = 50
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 69.095062/866, current 69.282120/876: elapsed=187055.0us expected=189743.1us +- 948.7us, error 1.4%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 69.095062/866, current 69.282120/876: elapsed=187055.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 69.282120
last_received_ts = 69.281792
last_seq = 876
current_ts = 69.469498
current_received_ts = 69.469154
current_seq = 886
count = 51
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 69.282120/876, current 69.469498/886: elapsed=187378.0us expected=189743.1us +- 948.7us, error 1.2%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 69.282120/876, current 69.469498/886: elapsed=187378.0us expected=189743.1us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 69.469498
last_received_ts = 69.469154
last_seq = 886
current_ts = 69.656868
current_received_ts = 69.656464
current_seq = 896
count = 52
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 69.469498/886, current 69.656868/896: elapsed=187374.0us expected=189743.1us +- 948.7us, error 1.2%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 69.469498/886, current 69.656868/896: elapsed=187374.0us expected=189743.1us
(kms_flip:2044) INFO: Event vblank: expected 527, counted 530, passrate = 66.04%, encoder type 2
(kms_flip:2044) DEBUG: dropped frames, expected 527, counted 530, passrate = 66.04%, encoder type 2
(kms_flip:2044) DEBUG: Retrying without a hotplug event
(kms_flip:2044) DEBUG: No stale events found
(kms_flip:2044) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2044) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2044) INFO: Expected frametime: 18974us; measured 18814.9us +- 5.994us accuracy 0.10%
(kms_flip:2044) INFO: vblank interval differs from modeline! expected 18973.8us, measured 18815us +- 5.994us, difference 158.8us (26.5 sigma)
(kms_flip:2044) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 73.290871
current_received_ts = 73.290497
current_seq = 1086
count = 0
seq_step = 10
(kms_flip:2044) DEBUG: name = vblank
last_ts = 73.290871
last_received_ts = 73.290497
last_seq = 1086
current_ts = 73.479225
current_received_ts = 73.479073
current_seq = 1096
count = 1
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 73.290871/1086, current 73.479225/1096: elapsed=188353.0us expected=188149.4us +- 940.7us, error 0.1%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 73.479225
last_received_ts = 73.479073
last_seq = 1096
current_ts = 73.667572
current_received_ts = 73.667229
current_seq = 1106
count = 2
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 73.479225/1096, current 73.667572/1106: elapsed=188348.0us expected=188149.4us +- 940.7us, error 0.1%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 73.667572
last_received_ts = 73.667229
last_seq = 1106
current_ts = 73.855927
current_received_ts = 73.855568
current_seq = 1116
count = 3
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 73.667572/1106, current 73.855927/1116: elapsed=188352.0us expected=188149.4us +- 940.7us, error 0.1%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 73.855927
last_received_ts = 73.855568
last_seq = 1116
current_ts = 74.044273
current_received_ts = 74.043861
current_seq = 1126
count = 4
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 73.855927/1116, current 74.044273/1126: elapsed=188347.0us expected=188149.4us +- 940.7us, error 0.1%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 74.044273
last_received_ts = 74.043861
last_seq = 1126
current_ts = 74.232620
current_received_ts = 74.232216
current_seq = 1136
count = 5
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 74.044273/1126, current 74.232620/1136: elapsed=188351.0us expected=188149.4us +- 940.7us, error 0.1%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 74.232620
last_received_ts = 74.232216
last_seq = 1136
current_ts = 74.421097
current_received_ts = 74.420792
current_seq = 1146
count = 6
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 74.232620/1136, current 74.421097/1146: elapsed=188476.0us expected=188149.4us +- 940.7us, error 0.2%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 74.421097
last_received_ts = 74.420792
last_seq = 1146
current_ts = 74.609634
current_received_ts = 74.609413
current_seq = 1156
count = 7
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 74.421097/1146, current 74.609634/1156: elapsed=188534.0us expected=188149.4us +- 940.7us, error 0.2%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 74.609634
last_received_ts = 74.609413
last_seq = 1156
current_ts = 74.798157
current_received_ts = 74.797836
current_seq = 1166
count = 8
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 74.609634/1156, current 74.798157/1166: elapsed=188524.0us expected=188149.4us +- 940.7us, error 0.2%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 74.798157
last_received_ts = 74.797836
last_seq = 1166
current_ts = 74.986664
current_received_ts = 74.986252
current_seq = 1176
count = 9
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 74.798157/1166, current 74.986664/1176: elapsed=188511.0us expected=188149.4us +- 940.7us, error 0.2%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 74.986664
last_received_ts = 74.986252
last_seq = 1176
current_ts = 75.175194
current_received_ts = 75.174988
current_seq = 1186
count = 10
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 74.986664/1176, current 75.175194/1186: elapsed=188523.0us expected=188149.4us +- 940.7us, error 0.2%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 75.175194
last_received_ts = 75.174988
last_seq = 1186
current_ts = 75.363800
current_received_ts = 75.363594
current_seq = 1196
count = 11
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 75.175194/1186, current 75.363800/1196: elapsed=188607.0us expected=188149.4us +- 940.7us, error 0.2%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 75.363800
last_received_ts = 75.363594
last_seq = 1196
current_ts = 75.552475
current_received_ts = 75.552177
current_seq = 1206
count = 12
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 75.363800/1196, current 75.552475/1206: elapsed=188681.0us expected=188149.4us +- 940.7us, error 0.3%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 75.552475
last_received_ts = 75.552177
last_seq = 1206
current_ts = 75.741150
current_received_ts = 75.740768
current_seq = 1216
count = 13
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 75.552475/1206, current 75.741150/1216: elapsed=188672.0us expected=188149.4us +- 940.7us, error 0.3%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 75.741150
last_received_ts = 75.740768
last_seq = 1216
current_ts = 75.929817
current_received_ts = 75.929611
current_seq = 1226
count = 14
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 75.741150/1216, current 75.929817/1226: elapsed=188670.0us expected=188149.4us +- 940.7us, error 0.3%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 75.929817
last_received_ts = 75.929611
last_seq = 1226
current_ts = 76.118500
current_received_ts = 76.118179
current_seq = 1236
count = 15
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 75.929817/1226, current 76.118500/1236: elapsed=188679.0us expected=188149.4us +- 940.7us, error 0.3%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 76.118500
last_received_ts = 76.118179
last_seq = 1236
current_ts = 76.307205
current_received_ts = 76.306984
current_seq = 1246
count = 16
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 76.118500/1236, current 76.307205/1246: elapsed=188706.0us expected=188149.4us +- 940.7us, error 0.3%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 76.307205
last_received_ts = 76.306984
last_seq = 1246
current_ts = 76.496017
current_received_ts = 76.495644
current_seq = 1256
count = 17
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 76.307205/1246, current 76.496017/1256: elapsed=188812.0us expected=188149.4us +- 940.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 76.496017
last_received_ts = 76.495644
last_seq = 1256
current_ts = 76.684822
current_received_ts = 76.684601
current_seq = 1266
count = 18
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 76.496017/1256, current 76.684822/1266: elapsed=188803.0us expected=188149.4us +- 940.7us, error 0.3%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 76.684822
last_received_ts = 76.684601
last_seq = 1266
current_ts = 76.873619
current_received_ts = 76.873230
current_seq = 1276
count = 19
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 76.684822/1266, current 76.873619/1276: elapsed=188800.0us expected=188149.4us +- 940.7us, error 0.3%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 76.873619
last_received_ts = 76.873230
last_seq = 1276
current_ts = 77.062431
current_received_ts = 77.062210
current_seq = 1286
count = 20
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 76.873619/1276, current 77.062431/1286: elapsed=188815.0us expected=188149.4us +- 940.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 77.062431
last_received_ts = 77.062210
last_seq = 1286
current_ts = 77.251236
current_received_ts = 77.250900
current_seq = 1296
count = 21
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 77.062431/1286, current 77.251236/1296: elapsed=188801.0us expected=188149.4us +- 940.7us, error 0.3%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 77.251236
last_received_ts = 77.250900
last_seq = 1296
current_ts = 77.440163
current_received_ts = 77.439941
current_seq = 1306
count = 22
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 77.251236/1296, current 77.440163/1306: elapsed=188926.0us expected=188149.4us +- 940.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 77.440163
last_received_ts = 77.439941
last_seq = 1306
current_ts = 77.629089
current_received_ts = 77.628860
current_seq = 1316
count = 23
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 77.440163/1306, current 77.629089/1316: elapsed=188924.0us expected=188149.4us +- 940.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 77.629089
last_received_ts = 77.628860
last_seq = 1316
current_ts = 77.818016
current_received_ts = 77.817459
current_seq = 1326
count = 24
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 77.629089/1316, current 77.818016/1326: elapsed=188929.0us expected=188149.4us +- 940.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 77.818016
last_received_ts = 77.817459
last_seq = 1326
current_ts = 78.006943
current_received_ts = 78.006630
current_seq = 1336
count = 25
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 77.818016/1326, current 78.006943/1336: elapsed=188925.0us expected=188149.4us +- 940.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 78.006943
last_received_ts = 78.006630
last_seq = 1336
current_ts = 78.195862
current_received_ts = 78.195457
current_seq = 1346
count = 26
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 78.006943/1336, current 78.195862/1346: elapsed=188921.0us expected=188149.4us +- 940.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 78.195862
last_received_ts = 78.195457
last_seq = 1346
current_ts = 78.384842
current_received_ts = 78.384628
current_seq = 1356
count = 27
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 78.195862/1346, current 78.384842/1356: elapsed=188984.0us expected=188149.4us +- 940.7us, error 0.4%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 78.384842
last_received_ts = 78.384628
last_seq = 1356
current_ts = 78.573868
current_received_ts = 78.573654
current_seq = 1366
count = 28
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 78.384842/1356, current 78.573868/1366: elapsed=189025.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 78.573868
last_received_ts = 78.573654
last_seq = 1366
current_ts = 78.762901
current_received_ts = 78.762596
current_seq = 1376
count = 29
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 78.573868/1366, current 78.762901/1376: elapsed=189032.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 78.762901
last_received_ts = 78.762596
last_seq = 1376
current_ts = 78.951927
current_received_ts = 78.951355
current_seq = 1386
count = 30
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 78.762901/1376, current 78.951927/1386: elapsed=189025.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 78.951927
last_received_ts = 78.951355
last_seq = 1386
current_ts = 79.140945
current_received_ts = 79.140289
current_seq = 1396
count = 31
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 78.951927/1386, current 79.140945/1396: elapsed=189017.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 79.140945
last_received_ts = 79.140289
last_seq = 1396
current_ts = 79.330002
current_received_ts = 79.329361
current_seq = 1406
count = 32
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 79.140945/1396, current 79.330002/1406: elapsed=189058.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: name = vblank
last_ts = 79.330002
last_received_ts = 79.329361
last_seq = 1406
current_ts = 79.519119
current_received_ts = 79.518494
current_seq = 1416
count = 33
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 79.330002/1406, current 79.519119/1416: elapsed=189117.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 79.330002/1406, current 79.519119/1416: elapsed=189117.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 79.519119
last_received_ts = 79.518494
last_seq = 1416
current_ts = 79.708237
current_received_ts = 79.707581
current_seq = 1426
count = 34
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 79.519119/1416, current 79.708237/1426: elapsed=189117.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 79.519119/1416, current 79.708237/1426: elapsed=189117.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 79.708237
last_received_ts = 79.707581
last_seq = 1426
current_ts = 79.897354
current_received_ts = 79.896736
current_seq = 1436
count = 35
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 79.708237/1426, current 79.897354/1436: elapsed=189115.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 79.708237/1426, current 79.897354/1436: elapsed=189115.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 79.897354
last_received_ts = 79.896736
last_seq = 1436
current_ts = 80.086472
current_received_ts = 80.086121
current_seq = 1446
count = 36
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 79.897354/1436, current 80.086472/1446: elapsed=189119.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 79.897354/1436, current 80.086472/1446: elapsed=189119.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 80.086472
last_received_ts = 80.086121
last_seq = 1446
current_ts = 80.275589
current_received_ts = 80.275406
current_seq = 1456
count = 37
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 80.086472/1446, current 80.275589/1456: elapsed=189120.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 80.086472/1446, current 80.275589/1456: elapsed=189120.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 80.275589
last_received_ts = 80.275406
last_seq = 1456
current_ts = 80.464775
current_received_ts = 80.464386
current_seq = 1466
count = 38
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 80.275589/1456, current 80.464775/1466: elapsed=189184.0us expected=188149.4us +- 940.7us, error 0.5%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 80.275589/1456, current 80.464775/1466: elapsed=189184.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 80.464775
last_received_ts = 80.464386
last_seq = 1466
current_ts = 80.653961
current_received_ts = 80.653595
current_seq = 1476
count = 39
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 80.464775/1466, current 80.653961/1476: elapsed=189190.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 80.464775/1466, current 80.653961/1476: elapsed=189190.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 80.653961
last_received_ts = 80.653595
last_seq = 1476
current_ts = 80.843155
current_received_ts = 80.842957
current_seq = 1486
count = 40
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 80.653961/1476, current 80.843155/1486: elapsed=189192.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 80.653961/1476, current 80.843155/1486: elapsed=189192.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 80.843155
last_received_ts = 80.842957
last_seq = 1486
current_ts = 81.032364
current_received_ts = 81.032150
current_seq = 1496
count = 41
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 80.843155/1486, current 81.032364/1496: elapsed=189207.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 80.843155/1486, current 81.032364/1496: elapsed=189207.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 81.032364
last_received_ts = 81.032150
last_seq = 1496
current_ts = 81.221550
current_received_ts = 81.221329
current_seq = 1506
count = 42
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 81.032364/1496, current 81.221550/1506: elapsed=189186.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 81.032364/1496, current 81.221550/1506: elapsed=189186.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 81.221550
last_received_ts = 81.221329
last_seq = 1506
current_ts = 81.410789
current_received_ts = 81.410431
current_seq = 1516
count = 43
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 81.221550/1506, current 81.410789/1516: elapsed=189243.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 81.221550/1506, current 81.410789/1516: elapsed=189243.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 81.410789
last_received_ts = 81.410431
last_seq = 1516
current_ts = 81.600052
current_received_ts = 81.599838
current_seq = 1526
count = 44
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 81.410789/1516, current 81.600052/1526: elapsed=189263.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 81.410789/1516, current 81.600052/1526: elapsed=189263.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 81.600052
last_received_ts = 81.599838
last_seq = 1526
current_ts = 81.789322
current_received_ts = 81.788933
current_seq = 1536
count = 45
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 81.600052/1526, current 81.789322/1536: elapsed=189264.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 81.600052/1526, current 81.789322/1536: elapsed=189264.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 81.789322
last_received_ts = 81.788933
last_seq = 1536
current_ts = 81.978577
current_received_ts = 81.978157
current_seq = 1546
count = 46
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 81.789322/1536, current 81.978577/1546: elapsed=189257.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 81.789322/1536, current 81.978577/1546: elapsed=189257.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 81.978577
last_received_ts = 81.978157
last_seq = 1546
current_ts = 82.167831
current_received_ts = 82.167480
current_seq = 1556
count = 47
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 81.978577/1546, current 82.167831/1556: elapsed=189257.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 81.978577/1546, current 82.167831/1556: elapsed=189257.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 82.167831
last_received_ts = 82.167480
last_seq = 1556
current_ts = 82.357132
current_received_ts = 82.356728
current_seq = 1566
count = 48
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 82.167831/1556, current 82.357132/1566: elapsed=189297.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 82.167831/1556, current 82.357132/1566: elapsed=189297.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 82.357132
last_received_ts = 82.356728
last_seq = 1566
current_ts = 82.546448
current_received_ts = 82.546135
current_seq = 1576
count = 49
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 82.357132/1566, current 82.546448/1576: elapsed=189314.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 82.357132/1566, current 82.546448/1576: elapsed=189314.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 82.546448
last_received_ts = 82.546135
last_seq = 1576
current_ts = 82.735771
current_received_ts = 82.735550
current_seq = 1586
count = 50
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 82.546448/1576, current 82.735771/1586: elapsed=189326.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 82.546448/1576, current 82.735771/1586: elapsed=189326.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 82.735771
last_received_ts = 82.735550
last_seq = 1586
current_ts = 82.925079
current_received_ts = 82.924774
current_seq = 1596
count = 51
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 82.735771/1586, current 82.925079/1596: elapsed=189310.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 82.735771/1586, current 82.925079/1596: elapsed=189310.0us expected=188149.4us
(kms_flip:2044) DEBUG: name = vblank
last_ts = 82.925079
last_received_ts = 82.924774
last_seq = 1596
current_ts = 83.114403
current_received_ts = 83.113892
current_seq = 1606
count = 52
seq_step = 10
(kms_flip:2044) DEBUG: vblank ts/seq: last 82.925079/1596, current 83.114403/1606: elapsed=189320.0us expected=188149.4us +- 940.7us, error 0.6%
(kms_flip:2044) DEBUG: inconsistent vblank ts/seq: last 82.925079/1596, current 83.114403/1606: elapsed=189320.0us expected=188149.4us
(kms_flip:2044) INFO: Event vblank: expected 532, counted 530, passrate = 62.26%, encoder type 2
(kms_flip:2044) DEBUG: dropped frames, expected 532, counted 530, passrate = 62.26%, encoder type 2
(kms_flip:2044) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1709:
(kms_flip:2044) CRITICAL: Failed assertion: !retried
(kms_flip:2044) igt_core-INFO: Stack trace:
(kms_flip:2044) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2044) igt_core-INFO:   #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
(kms_flip:2044) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:2044) igt_core-INFO:   #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
(kms_flip:2044) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:2044) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2044) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2044) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A2: FAIL (24.267s)
Dmesg
<6> [59.094601] Console: switching to colour dummy device 80x25
<6> [59.094666] [IGT] kms_flip: executing
<7> [59.099426] i915 0000:00:02.0: [drm:i915_gem_open [i915]]
<7> [59.100017] i915 0000:00:02.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x000001dc [0x000001dc]
<7> [59.100235] i915 0000:00:02.0: [drm:i915_gem_open [i915]]
<7> [59.104650] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:208:HDMI-A-1]
<7> [59.104659] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:208:HDMI-A-1]
<7> [59.108959] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:208:HDMI-A-1] disconnected
<7> [59.109365] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:222:DP-1]
<7> [59.109369] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:222:DP-1]
<7> [59.113588] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:222:DP-1] disconnected
<7> [59.114083] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:230:HDMI-A-3]
<7> [59.114089] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:230:HDMI-A-3]
<7> [59.118317] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:230:HDMI-A-3] disconnected
<7> [59.118612] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:208:HDMI-A-1]
<7> [59.118615] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:208:HDMI-A-1]
<7> [59.122803] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:208:HDMI-A-1] disconnected
<7> [59.122828] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:218:HDMI-A-2]
<7> [59.122832] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:218:HDMI-A-2]
<7> [59.148806] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:218:HDMI-A-2] Supported Monitor Refresh rate range is 0 Hz - 0 Hz
<7> [59.148814] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:218:HDMI-A-2] Assigning EDID-1.4 digital sink color depth as 8 bpc.
<7> [59.148816] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:218:HDMI-A-2] ELD monitor fitHeadless4k
<7> [59.148821] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:218:HDMI-A-2] ELD size 36, SAD count 0
<7> [59.149033] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK for addr: 0040 w(1)
<7> [59.149160] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK on first message, retry
<7> [59.149464] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK for addr: 0040 w(1)
<7> [59.149590] i915 0000:00:02.0: [drm:drm_dp_dual_mode_detect [drm_display_helper]] DP dual mode HDMI ID: (err -6)
<7> [59.149974] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1366x768": 216 268000 1366 1414 1446 1526 768 771 777 814 0x40 0x6 (CLOCK_HIGH)
<7> [59.149981] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74250 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE)
<7> [59.149985] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74176 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE)
<7> [59.149991] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:218:HDMI-A-2] probed modes:
<7> [59.149995] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [59.149998] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "4088x2304": 10 108000 4088 4152 4280 4536 2304 2305 2308 2340 0x40 0x5
<7> [59.150001] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "3840x2160": 15 128430 3840 3889 3921 4000 2160 2163 2169 2195 0x40 0xa
<7> [59.150004] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 11 60000 2880 2888 2984 3040 1800 1802 1820 1845 0x40 0xa
<7> [59.150007] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1600": 13 60000 2560 2568 2664 2720 1600 1602 1620 1645 0x40 0xa
<7> [59.150009] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1440": 15 60000 2560 2568 2664 2720 1440 1442 1460 1485 0x40 0xa
<7> [59.150012] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2048x1536": 17 60000 2048 2056 2152 2208 1536 1538 1556 1581 0x40 0xa
<7> [59.150014] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1600x1200": 60 162000 1600 1664 1856 2160 1200 1201 1204 1250 0x40 0x5
<7> [59.150017] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1680x1050": 60 146250 1680 1784 1960 2240 1050 1053 1059 1089 0x40 0x6
<7> [59.150020] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1600x900": 60 108000 1600 1624 1704 1800 900 901 904 1000 0x40 0x5
<7> [59.150022] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x1024": 75 135000 1280 1296 1440 1688 1024 1025 1028 1066 0x40 0x5
<7> [59.150025] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1360x768": 60 84963 1366 1431 1567 1776 768 771 781 798 0x0 0x6
<7> [59.150028] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1360x768": 20 25190 1360 1368 1464 1520 768 770 788 813 0x40 0xa
<7> [59.150030] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x800": 60 83500 1280 1352 1480 1680 800 803 809 831 0x40 0x6
<7> [59.150033] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1152x864": 75 108000 1152 1216 1344 1600 864 865 868 900 0x40 0x5
<7> [59.150035] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [59.150038] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [59.150041] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74176 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [59.150043] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 75 78750 1024 1040 1136 1312 768 769 772 800 0x40 0x5
<7> [59.150046] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 60 65000 1024 1048 1184 1344 768 771 777 806 0x40 0xa
<7> [59.150048] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1440x480": 60 54054 1440 1472 1596 1716 480 489 495 525 0x40 0xa
<7> [59.150051] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1440x480": 60 54000 1440 1472 1596 1716 480 489 495 525 0x40 0xa
<7> [59.150054] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x576": 60 46560 1024 1064 1160 1296 576 579 584 599 0x0 0x6
<7> [59.150056] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "832x624": 75 57284 832 864 928 1152 624 625 628 667 0x40 0xa
<7> [59.150059] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 75 49500 800 816 896 1056 600 601 604 625 0x40 0x5
<7> [59.150061] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 60 40000 800 840 968 1056 600 601 605 628 0x40 0x5
<7> [59.150064] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 75 31500 640 656 720 840 480 481 484 500 0x40 0xa
<7> [59.150067] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25200 640 656 752 800 480 490 492 525 0x40 0xa
<7> [59.150069] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa
<7> [59.150072] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa
<7> [59.150074] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "720x400": 70 28320 720 738 846 900 400 412 414 449 0x40 0x6
<7> [59.150096] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:222:DP-1]
<7> [59.150099] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:222:DP-1]
<7> [59.154307] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:222:DP-1] disconnected
<7> [59.154320] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:230:HDMI-A-3]
<7> [59.154323] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:230:HDMI-A-3]
<7> [59.158528] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:230:HDMI-A-3] disconnected
<6> [59.158968] [IGT] kms_flip: starting subtest wf_vblank-ts-check
<6> [59.160352] [IGT] kms_flip: starting dynamic subtest A-HDMI-A2
<7> [59.160651] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:233]
<7> [59.160757] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:237]
<7> [59.222156] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:89:pipe A]
<7> [59.222676] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [59.223023] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [59.223322] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [59.223586] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [59.223902] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [59.224160] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [59.224416] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [59.224672] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0)
<7> [59.224940] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [59.225168] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0)
<7> [59.225397] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [59.225627] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0)
<7> [59.225878] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [59.226105] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [59.226331] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [59.226556] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [59.226797] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [59.227021] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [59.227246] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [59.227470] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0)
<7> [59.227694] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [59.227903] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0)
<7> [59.228076] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [59.228249] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0)
<7> [59.228422] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [59.228612] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [59.228797] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [59.228976] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [59.229153] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [59.229329] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [59.229507] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [59.229684] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [59.229879] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [59.230054] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [59.230229] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0)
<7> [59.230407] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0)
<7> [59.230582] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in port_clock (expected 139929, found 0)
<7> [59.230765] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:89:pipe A] fastset requirement not met, forcing full modeset
<7> [59.230899] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:89:pipe A] releasing DPLL 0
<7> [59.231057] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no
<7> [59.231191] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:89:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [59.231344] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:33:plane 1A] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0
<7> [59.231477] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:83:cursor A] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0
<7> [59.231610] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [59.231764] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [59.231895] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [59.232025] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] min_ddb 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [59.232171] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:89:pipe A] data rate 0 num active planes 0
<7> [59.232306] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0
<7> [59.232455] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:89:pipe A] min cdclk: 69965 kHz -> 0 kHz
<7> [59.232605] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 8746 kHz -> 0 kHz
<7> [59.232757] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change
<7> [59.232888] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 180000 kHz, actual 180000 kHz
<7> [59.233018] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [59.233155] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:89:pipe A] enable: no [modeset]
<7> [59.233291] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:plane 1A] fb: [NOFB], visible: no
<7> [59.233424] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:43:plane 2A] fb: [NOFB], visible: no
<7> [59.233557] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:plane 3A] fb: [NOFB], visible: no
<7> [59.233689] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 4A] fb: [NOFB], visible: no
<7> [59.233834] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:73:plane 5A] fb: [NOFB], visible: no
<7> [59.233969] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:83:cursor A] fb: [NOFB], visible: no
<7> [59.250905] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [59.269903] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC1
<7> [59.271338] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:89:pipe A]
<7> [59.272191] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [59.272875] i915 0000:00:02.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:33:plane 1A]
<7> [59.273533] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 180000 kHz, VCO 720000 kHz, ref 24000 kHz, bypass 12000 kHz, voltage level 0
<7> [59.274472] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:207:DDI B/PHY B]
<7> [59.275121] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:217:DDI TC1/PHY C]
<7> [59.275819] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:221:DDI TC2/PHY D]
<7> [59.276375] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:223:DP-MST A]
<7> [59.276967] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:224:DP-MST B]
<7> [59.277530] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:225:DP-MST C]
<7> [59.278116] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:218:HDMI-A-2]
<7> [59.278984] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [59.279517] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3
<7> [59.280201] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:89:pipe A]
<7> [59.282139] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:147:pipe B]
<7> [59.282400] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:205:pipe C]
<7> [59.282632] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:89:pipe A]
<7> [59.282675] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:218:HDMI-A-2]
<7> [59.282805] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:218:HDMI-A-2] Limiting display bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)
<7> [59.283151] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [59.283461] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:89:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [59.283806] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:217:DDI TC1/PHY C] [CRTC:89:pipe A]
<7> [59.284122] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [59.284453] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [59.284764] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [59.285001] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [59.285236] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [59.285471] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [59.285707] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [59.285995] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360)
<7> [59.286228] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [59.286467] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360)
<7> [59.286707] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [59.286970] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096)
<7> [59.287206] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [59.287440] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [59.287684] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [59.287869] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [59.288036] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [59.288200] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [59.288365] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [59.288529] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360)
<7> [59.288692] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [59.288870] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360)
<7> [59.289034] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [59.289198] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096)
<7> [59.289379] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [59.289542] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [59.289706] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [59.289929] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [59.290098] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [59.290266] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [59.290432] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [59.290597] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [59.290777] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [59.290933] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [59.291066] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929)
<7> [59.291197] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929)
<7> [59.291328] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in port_clock (expected 0, found 139929)
<7> [59.291461] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:89:pipe A] fastset requirement not met, forcing full modeset
<7> [59.291627] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no
<7> [59.291770] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:89:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x1
<7> [59.291921] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:33:plane 1A] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016
<7> [59.292052] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:83:cursor A] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32
<7> [59.292182] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [59.292315] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0
<7> [59.292460] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0
<7> [59.292590] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0
<7> [59.292742] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:89:pipe A] data rate 559716 num active planes 1
<7> [59.292877] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560
<7> [59.293010] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [59.293157] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:89:pipe A] min cdclk: 0 kHz -> 69965 kHz
<7> [59.293303] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 8746 kHz
<7> [59.293436] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:89:pipe A] allocated DPLL 0
<7> [59.293574] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:89:pipe A] reserving DPLL 0
<7> [59.293719] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:89:pipe A] enable: yes [modeset]
<7> [59.293858] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [59.294031] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [59.294164] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [59.294308] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [59.294442] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [59.294582] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [59.294750] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [59.294883] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [59.295023] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [59.295153] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0
<7> [59.295290] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125
<7> [59.295420] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [59.295566] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [59.295697] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [59.295849] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5
<7> [59.295983] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [59.296116] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pipe src: 1920x1080+0+0, pixel rate 139929, min cdclk 69965
<7> [59.296248] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0
<7> [59.296380] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [59.296511] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [59.296642] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [59.296783] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0
<7> [59.296914] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [59.297045] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [59.297176] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [59.297307] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [59.297437] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [59.297567] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [59.297697] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [59.297845] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [59.297979] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [59.298109] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [59.298239] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [59.298368] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [59.298498] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [59.298628] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:plane 1A] fb: [FB:233] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [59.298775] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [59.298909] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [59.299043] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:43:plane 2A] fb: [NOFB], visible: no
<7> [59.299175] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:plane 3A] fb: [NOFB], visible: no
<7> [59.299306] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 4A] fb: [NOFB], visible: no
<7> [59.299436] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:73:plane 5A] fb: [NOFB], visible: no
<7> [59.299567] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:83:cursor A] fb: [NOFB], visible: no
<7> [59.301054] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3
<7> [59.301215] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:207:DDI B/PHY B]
<7> [59.301352] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:217:DDI TC1/PHY C]
<7> [59.301486] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:221:DDI TC2/PHY D]
<7> [59.301618] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:223:DP-MST A]
<7> [59.301766] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:224:DP-MST B]
<7> [59.301897] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:225:DP-MST C]
<7> [59.302061] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [59.302284] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:89:pipe A]
<7> [59.302421] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [59.302781] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC1
<7> [59.302953] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [59.303337] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [59.303474] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:33:plane 1A]
<7> [59.322490] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:218:HDMI-A-2]
<7> [59.322694] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:89:pipe A]
<6> [59.424132] pcieport 0000:00:06.0: AER: Correctable error message received from 0000:01:00.0
<4> [59.424153] nvme 0000:01:00.0: PCIe Bus Error: severity=Correctable, type=Physical Layer, (Receiver ID)
<4> [59.424160] nvme 0000:01:00.0: device [15b7:5006] error status/mask=00000001/0000e000
<4> [59.424167] nvme 0000:01:00.0: [ 0] RxErr (First)
<7> [72.775641] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:89:pipe A]
<7> [72.775983] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [72.776668] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [72.777357] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [72.778008] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [72.778625] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [72.779284] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [72.779911] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [72.780534] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0)
<7> [72.780872] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [72.781006] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0)
<7> [72.781140] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [72.781272] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0)
<7> [72.781404] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [72.781537] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [72.781668] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [72.781812] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [72.781948] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [72.782082] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [72.782216] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [72.782348] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0)
<7> [72.782480] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [72.782612] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0)
<7> [72.782744] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [72.782884] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0)
<7> [72.783016] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [72.783147] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [72.783278] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [72.783410] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [72.783542] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [72.783673] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [72.783808] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [72.783939] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [72.784070] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [72.784203] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [72.784333] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0)
<7> [72.784464] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0)
<7> [72.784595] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in port_clock (expected 139929, found 0)
<7> [72.784726] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:89:pipe A] fastset requirement not met, forcing full modeset
<7> [72.784872] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:89:pipe A] releasing DPLL 0
<7> [72.785032] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no
<7> [72.785166] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:89:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [72.785317] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:33:plane 1A] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0
<7> [72.785448] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:83:cursor A] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0
<7> [72.785578] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [72.785710] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [72.785855] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [72.785986] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] min_ddb 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [72.786133] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:89:pipe A] data rate 0 num active planes 0
<7> [72.786268] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0
<7> [72.786416] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:89:pipe A] min cdclk: 69965 kHz -> 0 kHz
<7> [72.786566] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 8746 kHz -> 0 kHz
<7> [72.786703] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:89:pipe A] enable: no [modeset]
<7> [72.786844] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:plane 1A] fb: [NOFB], visible: no
<7> [72.786977] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:43:plane 2A] fb: [NOFB], visible: no
<7> [72.787110] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:plane 3A] fb: [NOFB], visible: no
<7> [72.787241] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 4A] fb: [NOFB], visible: no
<7> [72.787374] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:73:plane 5A] fb: [NOFB], visible: no
<7> [72.787504] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:83:cursor A] fb: [NOFB], visible: no
<7> [72.793785] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [72.813130] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC1
<7> [72.813627] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:89:pipe A]
<7> [72.814250] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [72.814753] i915 0000:00:02.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:33:plane 1A]
<7> [72.815277] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:207:DDI B/PHY B]
<7> [72.815758] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:217:DDI TC1/PHY C]
<7> [72.816303] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:221:DDI TC2/PHY D]
<7> [72.816781] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:223:DP-MST A]
<7> [72.817263] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:224:DP-MST B]
<7> [72.817700] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:225:DP-MST C]
<7> [72.818160] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:218:HDMI-A-2]
<7> [72.818773] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [72.819328] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3
<7> [72.819840] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:89:pipe A]
<7> [72.820779] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:147:pipe B]
<7> [72.821058] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:205:pipe C]
<7> [72.821330] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:89:pipe A]
<7> [72.821373] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:218:HDMI-A-2]
<7> [72.821482] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:218:HDMI-A-2] Limiting display bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)
<7> [72.821845] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [72.822202] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:89:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [72.822550] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:217:DDI TC1/PHY C] [CRTC:89:pipe A]
<7> [72.822885] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [72.823248] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [72.823554] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [72.823821] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [72.824089] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [72.824377] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [72.824643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [72.824915] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360)
<7> [72.825169] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [72.825503] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360)
<7> [72.825773] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [72.826039] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096)
<7> [72.826266] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [72.826487] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [72.826719] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [72.826929] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [72.827067] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [72.827217] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [72.827385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [72.827518] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360)
<7> [72.827660] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [72.827795] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360)
<7> [72.827936] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [72.828069] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096)
<7> [72.828215] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [72.828389] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [72.828531] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [72.828663] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [72.828795] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [72.828927] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [72.829058] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [72.829204] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [72.829335] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [72.829466] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [72.829598] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929)
<7> [72.829730] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929)
<7> [72.829873] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:89:pipe A] fastset requirement not met in port_clock (expected 0, found 139929)
<7> [72.830016] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:89:pipe A] fastset requirement not met, forcing full modeset
<7> [72.830173] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no
<7> [72.830343] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:89:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x1
<7> [72.830518] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:33:plane 1A] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016
<7> [72.830653] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:83:cursor A] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32
<7> [72.830787] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [72.830924] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0
<7> [72.831055] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0
<7> [72.831222] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:33:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0
<7> [72.831418] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:89:pipe A] data rate 559716 num active planes 1
<7> [72.831555] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560
<7> [72.831695] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [72.831841] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:89:pipe A] min cdclk: 0 kHz -> 69965 kHz
<7> [72.831996] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 8746 kHz
<7> [72.832143] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:89:pipe A] allocated DPLL 0
<7> [72.832319] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:89:pipe A] reserving DPLL 0
<7> [72.832457] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:89:pipe A] enable: yes [modeset]
<7> [72.832599] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [72.832739] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [72.832871] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [72.833038] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [72.833169] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [72.833323] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [72.833457] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [72.833599] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [72.833767] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [72.833899] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0
<7> [72.834038] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125
<7> [72.834168] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [72.834323] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5
<7> [72.834459] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [72.834619] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5
<7> [72.834781] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [72.834913] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pipe src: 1920x1080+0+0, pixel rate 139929, min cdclk 69965
<7> [72.835044] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0
<7> [72.835175] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [72.835354] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [72.835484] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [72.835618] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0
<7> [72.835754] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [72.835886] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [72.836017] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [72.836149] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [72.836294] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [72.836424] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [72.836553] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [72.836683] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [72.836814] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [72.836944] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [72.837074] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [72.837203] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [72.837350] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [72.837485] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:plane 1A] fb: [FB:233] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [72.837620] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [72.837752] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [72.837883] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:43:plane 2A] fb: [NOFB], visible: no
<7> [72.838014] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:plane 3A] fb: [NOFB], visible: no
<7> [72.838147] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 4A] fb: [NOFB], visible: no
<7> [72.838299] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:73:plane 5A] fb: [NOFB], visible: no
<7> [72.838432] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:83:cursor A] fb: [NOFB], visible: no
<7> [72.838643] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3
<7> [72.838794] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:207:DDI B/PHY B]
<7> [72.838930] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:217:DDI TC1/PHY C]
<7> [72.839063] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:221:DDI TC2/PHY D]
<7> [72.839198] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:223:DP-MST A]
<7> [72.839359] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:224:DP-MST B]
<7> [72.839491] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:225:DP-MST C]
<7> [72.839657] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [72.839878] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:89:pipe A]
<7> [72.840016] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [72.840203] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC1
<7> [72.840389] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [72.840763] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [72.840901] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:33:plane 1A]
<7> [72.859874] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:218:HDMI-A-2]
<7> [72.860074] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:89:pipe A]
<6> [83.427307] [IGT] kms_flip: finished subtest A-HDMI-A2, FAIL
Created at 2025-11-29 00:16:01