Results for igt@kms_flip@wf_vblank-ts-check@a-edp1

Result: Fail

i915_display_info14 igt_runner14 results14.json results14-xe-load.json guc_logs14.tar i915_display_info_post_exec14 serial_data14 boot14 dmesg14

DetailValue
Duration 26.55 seconds
Hostname 
shard-lnl-5
Igt-Version 
IGT-Version: 2.4-gd28bd0b9e (x86_64) (Linux: 7.1.0-rc3-lgci-xe-xe-pw-166311v1-debug+ x86_64)
Out 
Using IGT_SRANDOM=1778517811 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: wf_vblank-ts-check
Starting dynamic subtest: A-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Expected frametime: 16664us; measured 16714.4us +- 3.812us accuracy 0.07%
vblank interval differs from modeline! expected 16664.0us, measured 16714us +- 3.812us, difference 50.4us (13.2 sigma)
Event vblank: expected 605, counted 610, passrate = 75.41%, encoder type 2
Expected frametime: 16664us; measured 16475.9us +- 4.582us accuracy 0.08%
vblank interval differs from modeline! expected 16664.0us, measured 16476us +- 4.582us, difference 188.1us (41.0 sigma)
Event vblank: expected 613, counted 610, passrate = 40.98%, encoder type 2
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:1071 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (26.551s)
Err 
Starting subtest: wf_vblank-ts-check
Starting dynamic subtest: A-eDP1
(kms_flip:7611) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1722:
(kms_flip:7611) CRITICAL: Failed assertion: !retried
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:7611) DEBUG: name = vblank
last_ts = 384.760498
last_received_ts = 384.760101
last_seq = 3183
current_ts = 384.927429
current_received_ts = 384.927124
current_seq = 3193
count = 30
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 384.760498/3183, current 384.927429/3193: elapsed=166940.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 384.927429
last_received_ts = 384.927124
last_seq = 3193
current_ts = 385.094391
current_received_ts = 385.093933
current_seq = 3203
count = 31
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 384.927429/3193, current 385.094391/3203: elapsed=166939.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 385.094391
last_received_ts = 385.093933
last_seq = 3203
current_ts = 385.261322
current_received_ts = 385.260925
current_seq = 3213
count = 32
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 385.094391/3203, current 385.261322/3213: elapsed=166934.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 385.261322
last_received_ts = 385.260925
last_seq = 3213
current_ts = 385.428253
current_received_ts = 385.427826
current_seq = 3223
count = 33
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 385.261322/3213, current 385.428253/3223: elapsed=166945.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 385.428253
last_received_ts = 385.427826
last_seq = 3223
current_ts = 385.595184
current_received_ts = 385.594757
current_seq = 3233
count = 34
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 385.428253/3223, current 385.595184/3233: elapsed=166914.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 385.595184
last_received_ts = 385.594757
last_seq = 3233
current_ts = 385.762085
current_received_ts = 385.761658
current_seq = 3243
count = 35
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 385.595184/3233, current 385.762085/3243: elapsed=166909.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 385.762085
last_received_ts = 385.761658
last_seq = 3243
current_ts = 385.928986
current_received_ts = 385.928589
current_seq = 3253
count = 36
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 385.762085/3243, current 385.928986/3253: elapsed=166911.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 385.928986
last_received_ts = 385.928589
last_seq = 3253
current_ts = 386.095917
current_received_ts = 386.095490
current_seq = 3263
count = 37
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 385.928986/3253, current 386.095917/3263: elapsed=166918.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 386.095917
last_received_ts = 386.095490
last_seq = 3263
current_ts = 386.262817
current_received_ts = 386.262390
current_seq = 3273
count = 38
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 386.095917/3263, current 386.262817/3273: elapsed=166909.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 386.262817
last_received_ts = 386.262390
last_seq = 3273
current_ts = 386.429718
current_received_ts = 386.429321
current_seq = 3283
count = 39
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 386.262817/3273, current 386.429718/3283: elapsed=166913.0us expected=167144.4us +- 835.7us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 386.429718
last_received_ts = 386.429321
last_seq = 3283
current_ts = 386.596619
current_received_ts = 386.596222
current_seq = 3293
count = 40
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 386.429718/3283, current 386.596619/3293: elapsed=166886.0us expected=167144.4us +- 835.7us, error 0.2%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 386.596619
last_received_ts = 386.596222
last_seq = 3293
current_ts = 386.763519
current_received_ts = 386.763153
current_seq = 3303
count = 41
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 386.596619/3293, current 386.763519/3303: elapsed=166892.0us expected=167144.4us +- 835.7us, error 0.2%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 386.763519
last_received_ts = 386.763153
last_seq = 3303
current_ts = 386.930389
current_received_ts = 386.929962
current_seq = 3313
count = 42
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 386.763519/3303, current 386.930389/3313: elapsed=166888.0us expected=167144.4us +- 835.7us, error 0.2%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 386.930389
last_received_ts = 386.929962
last_seq = 3313
current_ts = 387.097290
current_received_ts = 387.096863
current_seq = 3323
count = 43
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 386.930389/3313, current 387.097290/3323: elapsed=166891.0us expected=167144.4us +- 835.7us, error 0.2%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 387.097290
last_received_ts = 387.096863
last_seq = 3323
current_ts = 387.264099
current_received_ts = 387.263733
current_seq = 3333
count = 44
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 387.097290/3323, current 387.264099/3333: elapsed=166825.0us expected=167144.4us +- 835.7us, error 0.2%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 387.264099
last_received_ts = 387.263733
last_seq = 3333
current_ts = 387.430450
current_received_ts = 387.430084
current_seq = 3343
count = 45
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 387.264099/3333, current 387.430450/3343: elapsed=166343.0us expected=167144.4us +- 835.7us, error 0.5%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 387.430450
last_received_ts = 387.430084
last_seq = 3343
current_ts = 387.592987
current_received_ts = 387.592560
current_seq = 3353
count = 46
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 387.430450/3343, current 387.592987/3353: elapsed=162543.0us expected=167144.4us +- 835.7us, error 2.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 387.430450/3343, current 387.592987/3353: elapsed=162543.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 387.592987
last_received_ts = 387.592560
last_seq = 3353
current_ts = 387.755554
current_received_ts = 387.755157
current_seq = 3363
count = 47
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 387.592987/3353, current 387.755554/3363: elapsed=162554.0us expected=167144.4us +- 835.7us, error 2.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 387.592987/3353, current 387.755554/3363: elapsed=162554.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 387.755554
last_received_ts = 387.755157
last_seq = 3363
current_ts = 387.918091
current_received_ts = 387.917694
current_seq = 3373
count = 48
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 387.755554/3363, current 387.918091/3373: elapsed=162548.0us expected=167144.4us +- 835.7us, error 2.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 387.755554/3363, current 387.918091/3373: elapsed=162548.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 387.918091
last_received_ts = 387.917694
last_seq = 3373
current_ts = 388.080658
current_received_ts = 388.080231
current_seq = 3383
count = 49
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 387.918091/3373, current 388.080658/3383: elapsed=162550.0us expected=167144.4us +- 835.7us, error 2.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 387.918091/3373, current 388.080658/3383: elapsed=162550.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 388.080658
last_received_ts = 388.080231
last_seq = 3383
current_ts = 388.243195
current_received_ts = 388.242798
current_seq = 3393
count = 50
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 388.080658/3383, current 388.243195/3393: elapsed=162543.0us expected=167144.4us +- 835.7us, error 2.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 388.080658/3383, current 388.243195/3393: elapsed=162543.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 388.243195
last_received_ts = 388.242798
last_seq = 3393
current_ts = 388.405731
current_received_ts = 388.405304
current_seq = 3403
count = 51
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 388.243195/3393, current 388.405731/3403: elapsed=162551.0us expected=167144.4us +- 835.7us, error 2.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 388.243195/3393, current 388.405731/3403: elapsed=162551.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 388.405731
last_received_ts = 388.405304
last_seq = 3403
current_ts = 388.568756
current_received_ts = 388.568146
current_seq = 3413
count = 52
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 388.405731/3403, current 388.568756/3413: elapsed=163006.0us expected=167144.4us +- 835.7us, error 2.5%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 388.405731/3403, current 388.568756/3413: elapsed=163006.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 388.568756
last_received_ts = 388.568146
last_seq = 3413
current_ts = 388.731781
current_received_ts = 388.731384
current_seq = 3423
count = 53
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 388.568756/3413, current 388.731781/3423: elapsed=163043.0us expected=167144.4us +- 835.7us, error 2.5%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 388.568756/3413, current 388.731781/3423: elapsed=163043.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 388.731781
last_received_ts = 388.731384
last_seq = 3423
current_ts = 388.894836
current_received_ts = 388.894470
current_seq = 3433
count = 54
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 388.731781/3423, current 388.894836/3433: elapsed=163048.0us expected=167144.4us +- 835.7us, error 2.5%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 388.731781/3423, current 388.894836/3433: elapsed=163048.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 388.894836
last_received_ts = 388.894470
last_seq = 3433
current_ts = 389.057892
current_received_ts = 389.057434
current_seq = 3443
count = 55
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 388.894836/3433, current 389.057892/3443: elapsed=163051.0us expected=167144.4us +- 835.7us, error 2.4%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 388.894836/3433, current 389.057892/3443: elapsed=163051.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 389.057892
last_received_ts = 389.057434
last_seq = 3443
current_ts = 389.220947
current_received_ts = 389.220520
current_seq = 3453
count = 56
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 389.057892/3443, current 389.220947/3453: elapsed=163050.0us expected=167144.4us +- 835.7us, error 2.4%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 389.057892/3443, current 389.220947/3453: elapsed=163050.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 389.220947
last_received_ts = 389.220520
last_seq = 3453
current_ts = 389.384003
current_received_ts = 389.383575
current_seq = 3463
count = 57
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 389.220947/3453, current 389.384003/3463: elapsed=163054.0us expected=167144.4us +- 835.7us, error 2.4%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 389.220947/3453, current 389.384003/3463: elapsed=163054.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 389.384003
last_received_ts = 389.383575
last_seq = 3463
current_ts = 389.547394
current_received_ts = 389.546783
current_seq = 3473
count = 58
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 389.384003/3463, current 389.547394/3473: elapsed=163405.0us expected=167144.4us +- 835.7us, error 2.2%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 389.384003/3463, current 389.547394/3473: elapsed=163405.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 389.547394
last_received_ts = 389.546783
last_seq = 3473
current_ts = 389.710876
current_received_ts = 389.710419
current_seq = 3483
count = 59
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 389.547394/3473, current 389.710876/3483: elapsed=163480.0us expected=167144.4us +- 835.7us, error 2.2%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 389.547394/3473, current 389.710876/3483: elapsed=163480.0us expected=167144.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 389.710876
last_received_ts = 389.710419
last_seq = 3483
current_ts = 389.874359
current_received_ts = 389.873932
current_seq = 3493
count = 60
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 389.710876/3483, current 389.874359/3493: elapsed=163489.0us expected=167144.4us +- 835.7us, error 2.2%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 389.710876/3483, current 389.874359/3493: elapsed=163489.0us expected=167144.4us
(kms_flip:7611) INFO: Event vblank: expected 605, counted 610, passrate = 75.41%, encoder type 2
(kms_flip:7611) DEBUG: dropped frames, expected 605, counted 610, passrate = 75.41%, encoder type 2
(kms_flip:7611) DEBUG: Retrying without a hotplug event
(kms_flip:7611) DEBUG: No stale events found
(kms_flip:7611) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:7611) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:7611) INFO: Expected frametime: 16664us; measured 16475.9us +- 4.582us accuracy 0.08%
(kms_flip:7611) INFO: vblank interval differs from modeline! expected 16664.0us, measured 16476us +- 4.582us, difference 188.1us (41.0 sigma)
(kms_flip:7611) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 394.514465
current_received_ts = 394.513885
current_seq = 3525
count = 0
seq_step = 10
(kms_flip:7611) DEBUG: name = vblank
last_ts = 394.514465
last_received_ts = 394.513885
last_seq = 3525
current_ts = 394.679443
current_received_ts = 394.678864
current_seq = 3535
count = 1
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 394.514465/3525, current 394.679443/3535: elapsed=164984.0us expected=164759.4us +- 823.8us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 394.679443
last_received_ts = 394.678864
last_seq = 3535
current_ts = 394.844452
current_received_ts = 394.843842
current_seq = 3545
count = 2
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 394.679443/3535, current 394.844452/3545: elapsed=164989.0us expected=164759.4us +- 823.8us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 394.844452
last_received_ts = 394.843842
last_seq = 3545
current_ts = 395.009430
current_received_ts = 395.008820
current_seq = 3555
count = 3
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 394.844452/3545, current 395.009430/3555: elapsed=164977.0us expected=164759.4us +- 823.8us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 395.009430
last_received_ts = 395.008820
last_seq = 3555
current_ts = 395.174408
current_received_ts = 395.173798
current_seq = 3565
count = 4
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 395.009430/3555, current 395.174408/3565: elapsed=164983.0us expected=164759.4us +- 823.8us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 395.174408
last_received_ts = 395.173798
last_seq = 3565
current_ts = 395.339386
current_received_ts = 395.338806
current_seq = 3575
count = 5
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 395.174408/3565, current 395.339386/3575: elapsed=164987.0us expected=164759.4us +- 823.8us, error 0.1%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 395.339386
last_received_ts = 395.338806
last_seq = 3575
current_ts = 395.504456
current_received_ts = 395.503845
current_seq = 3585
count = 6
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 395.339386/3575, current 395.504456/3585: elapsed=165080.0us expected=164759.4us +- 823.8us, error 0.2%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 395.504456
last_received_ts = 395.503845
last_seq = 3585
current_ts = 395.669647
current_received_ts = 395.669067
current_seq = 3595
count = 7
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 395.504456/3585, current 395.669647/3595: elapsed=165180.0us expected=164759.4us +- 823.8us, error 0.3%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 395.669647
last_received_ts = 395.669067
last_seq = 3595
current_ts = 395.834839
current_received_ts = 395.834229
current_seq = 3605
count = 8
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 395.669647/3595, current 395.834839/3605: elapsed=165179.0us expected=164759.4us +- 823.8us, error 0.3%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 395.834839
last_received_ts = 395.834229
last_seq = 3605
current_ts = 396.000000
current_received_ts = 395.999390
current_seq = 3615
count = 9
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 395.834839/3605, current 396.000000/3615: elapsed=165176.0us expected=164759.4us +- 823.8us, error 0.3%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 396.000000
last_received_ts = 395.999390
last_seq = 3615
current_ts = 396.165192
current_received_ts = 396.164612
current_seq = 3625
count = 10
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 396.000000/3615, current 396.165192/3625: elapsed=165183.0us expected=164759.4us +- 823.8us, error 0.3%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 396.165192
last_received_ts = 396.164612
last_seq = 3625
current_ts = 396.330353
current_received_ts = 396.329773
current_seq = 3635
count = 11
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 396.165192/3625, current 396.330353/3635: elapsed=165178.0us expected=164759.4us +- 823.8us, error 0.3%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 396.330353
last_received_ts = 396.329773
last_seq = 3635
current_ts = 396.495605
current_received_ts = 396.495026
current_seq = 3645
count = 12
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 396.330353/3635, current 396.495605/3645: elapsed=165248.0us expected=164759.4us +- 823.8us, error 0.3%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 396.495605
last_received_ts = 396.495026
last_seq = 3645
current_ts = 396.660980
current_received_ts = 396.660431
current_seq = 3655
count = 13
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 396.495605/3645, current 396.660980/3655: elapsed=165356.0us expected=164759.4us +- 823.8us, error 0.4%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 396.660980
last_received_ts = 396.660431
last_seq = 3655
current_ts = 396.826324
current_received_ts = 396.825714
current_seq = 3665
count = 14
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 396.660980/3655, current 396.826324/3665: elapsed=165354.0us expected=164759.4us +- 823.8us, error 0.4%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 396.826324
last_received_ts = 396.825714
last_seq = 3665
current_ts = 396.991669
current_received_ts = 396.991058
current_seq = 3675
count = 15
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 396.826324/3665, current 396.991669/3675: elapsed=165349.0us expected=164759.4us +- 823.8us, error 0.4%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 396.991669
last_received_ts = 396.991058
last_seq = 3675
current_ts = 397.157013
current_received_ts = 397.156464
current_seq = 3685
count = 16
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 396.991669/3675, current 397.157013/3685: elapsed=165351.0us expected=164759.4us +- 823.8us, error 0.4%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 397.157013
last_received_ts = 397.156464
last_seq = 3685
current_ts = 397.322388
current_received_ts = 397.321777
current_seq = 3695
count = 17
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 397.157013/3685, current 397.322388/3695: elapsed=165355.0us expected=164759.4us +- 823.8us, error 0.4%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 397.322388
last_received_ts = 397.321777
last_seq = 3695
current_ts = 397.487793
current_received_ts = 397.487213
current_seq = 3705
count = 18
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 397.322388/3695, current 397.487793/3705: elapsed=165409.0us expected=164759.4us +- 823.8us, error 0.4%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 397.487793
last_received_ts = 397.487213
last_seq = 3705
current_ts = 397.653290
current_received_ts = 397.652679
current_seq = 3715
count = 19
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 397.487793/3705, current 397.653290/3715: elapsed=165499.0us expected=164759.4us +- 823.8us, error 0.4%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 397.653290
last_received_ts = 397.652679
last_seq = 3715
current_ts = 397.818787
current_received_ts = 397.818207
current_seq = 3725
count = 20
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 397.653290/3715, current 397.818787/3725: elapsed=165503.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 397.818787
last_received_ts = 397.818207
last_seq = 3725
current_ts = 397.984314
current_received_ts = 397.983673
current_seq = 3735
count = 21
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 397.818787/3725, current 397.984314/3735: elapsed=165510.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 397.984314
last_received_ts = 397.983673
last_seq = 3735
current_ts = 398.149780
current_received_ts = 398.149200
current_seq = 3745
count = 22
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 397.984314/3735, current 398.149780/3745: elapsed=165494.0us expected=164759.4us +- 823.8us, error 0.4%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 398.149780
last_received_ts = 398.149200
last_seq = 3745
current_ts = 398.315308
current_received_ts = 398.314697
current_seq = 3755
count = 23
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 398.149780/3745, current 398.315308/3755: elapsed=165504.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 398.315308
last_received_ts = 398.314697
last_seq = 3755
current_ts = 398.480835
current_received_ts = 398.480286
current_seq = 3765
count = 24
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 398.315308/3755, current 398.480835/3765: elapsed=165546.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: name = vblank
last_ts = 398.480835
last_received_ts = 398.480286
last_seq = 3765
current_ts = 398.646484
current_received_ts = 398.645935
current_seq = 3775
count = 25
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 398.480835/3765, current 398.646484/3775: elapsed=165642.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 398.480835/3765, current 398.646484/3775: elapsed=165642.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 398.646484
last_received_ts = 398.645935
last_seq = 3775
current_ts = 398.812103
current_received_ts = 398.811462
current_seq = 3785
count = 26
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 398.646484/3775, current 398.812103/3785: elapsed=165630.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 398.646484/3775, current 398.812103/3785: elapsed=165630.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 398.812103
last_received_ts = 398.811462
last_seq = 3785
current_ts = 398.977753
current_received_ts = 398.977142
current_seq = 3795
count = 27
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 398.812103/3785, current 398.977753/3795: elapsed=165636.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 398.812103/3785, current 398.977753/3795: elapsed=165636.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 398.977753
last_received_ts = 398.977142
last_seq = 3795
current_ts = 399.143372
current_received_ts = 399.142853
current_seq = 3805
count = 28
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 398.977753/3795, current 399.143372/3805: elapsed=165630.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 398.977753/3795, current 399.143372/3805: elapsed=165630.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 399.143372
last_received_ts = 399.142853
last_seq = 3805
current_ts = 399.309021
current_received_ts = 399.308411
current_seq = 3815
count = 29
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 399.143372/3805, current 399.309021/3815: elapsed=165640.0us expected=164759.4us +- 823.8us, error 0.5%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 399.143372/3805, current 399.309021/3815: elapsed=165640.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 399.309021
last_received_ts = 399.308411
last_seq = 3815
current_ts = 399.474701
current_received_ts = 399.474091
current_seq = 3825
count = 30
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 399.309021/3815, current 399.474701/3825: elapsed=165666.0us expected=164759.4us +- 823.8us, error 0.6%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 399.309021/3815, current 399.474701/3825: elapsed=165666.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 399.474701
last_received_ts = 399.474091
last_seq = 3825
current_ts = 399.640442
current_received_ts = 399.639832
current_seq = 3835
count = 31
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 399.474701/3825, current 399.640442/3835: elapsed=165746.0us expected=164759.4us +- 823.8us, error 0.6%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 399.474701/3825, current 399.640442/3835: elapsed=165746.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 399.640442
last_received_ts = 399.639832
last_seq = 3835
current_ts = 399.806183
current_received_ts = 399.805573
current_seq = 3845
count = 32
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 399.640442/3835, current 399.806183/3845: elapsed=165750.0us expected=164759.4us +- 823.8us, error 0.6%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 399.640442/3835, current 399.806183/3845: elapsed=165750.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 399.806183
last_received_ts = 399.805573
last_seq = 3845
current_ts = 399.971954
current_received_ts = 399.971313
current_seq = 3855
count = 33
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 399.806183/3845, current 399.971954/3855: elapsed=165756.0us expected=164759.4us +- 823.8us, error 0.6%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 399.806183/3845, current 399.971954/3855: elapsed=165756.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 399.971954
last_received_ts = 399.971313
last_seq = 3855
current_ts = 400.137695
current_received_ts = 400.137115
current_seq = 3865
count = 34
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 399.971954/3855, current 400.137695/3865: elapsed=165746.0us expected=164759.4us +- 823.8us, error 0.6%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 399.971954/3855, current 400.137695/3865: elapsed=165746.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 400.137695
last_received_ts = 400.137115
last_seq = 3865
current_ts = 400.303436
current_received_ts = 400.302856
current_seq = 3875
count = 35
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 400.137695/3865, current 400.303436/3875: elapsed=165748.0us expected=164759.4us +- 823.8us, error 0.6%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 400.137695/3865, current 400.303436/3875: elapsed=165748.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 400.303436
last_received_ts = 400.302856
last_seq = 3875
current_ts = 400.469208
current_received_ts = 400.468597
current_seq = 3885
count = 36
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 400.303436/3875, current 400.469208/3885: elapsed=165781.0us expected=164759.4us +- 823.8us, error 0.6%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 400.303436/3875, current 400.469208/3885: elapsed=165781.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 400.469208
last_received_ts = 400.468597
last_seq = 3885
current_ts = 400.635071
current_received_ts = 400.634460
current_seq = 3895
count = 37
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 400.469208/3885, current 400.635071/3895: elapsed=165848.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 400.469208/3885, current 400.635071/3895: elapsed=165848.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 400.635071
last_received_ts = 400.634460
last_seq = 3895
current_ts = 400.800903
current_received_ts = 400.800323
current_seq = 3905
count = 38
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 400.635071/3895, current 400.800903/3905: elapsed=165853.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 400.635071/3895, current 400.800903/3905: elapsed=165853.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 400.800903
last_received_ts = 400.800323
last_seq = 3905
current_ts = 400.966766
current_received_ts = 400.966156
current_seq = 3915
count = 39
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 400.800903/3905, current 400.966766/3915: elapsed=165851.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 400.800903/3905, current 400.966766/3915: elapsed=165851.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 400.966766
last_received_ts = 400.966156
last_seq = 3915
current_ts = 401.132629
current_received_ts = 401.132050
current_seq = 3925
count = 40
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 400.966766/3915, current 401.132629/3925: elapsed=165850.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 400.966766/3915, current 401.132629/3925: elapsed=165850.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 401.132629
last_received_ts = 401.132050
last_seq = 3925
current_ts = 401.298462
current_received_ts = 401.297882
current_seq = 3935
count = 41
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 401.132629/3925, current 401.298462/3935: elapsed=165848.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 401.132629/3925, current 401.298462/3935: elapsed=165848.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 401.298462
last_received_ts = 401.297882
last_seq = 3935
current_ts = 401.464325
current_received_ts = 401.463776
current_seq = 3945
count = 42
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 401.298462/3935, current 401.464325/3945: elapsed=165875.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 401.298462/3935, current 401.464325/3945: elapsed=165875.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 401.464325
last_received_ts = 401.463776
last_seq = 3945
current_ts = 401.630280
current_received_ts = 401.629700
current_seq = 3955
count = 43
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 401.464325/3945, current 401.630280/3955: elapsed=165946.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 401.464325/3945, current 401.630280/3955: elapsed=165946.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 401.630280
last_received_ts = 401.629700
last_seq = 3955
current_ts = 401.796234
current_received_ts = 401.795624
current_seq = 3965
count = 44
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 401.630280/3955, current 401.796234/3965: elapsed=165937.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 401.630280/3955, current 401.796234/3965: elapsed=165937.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 401.796234
last_received_ts = 401.795624
last_seq = 3965
current_ts = 401.962158
current_received_ts = 401.961578
current_seq = 3975
count = 45
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 401.796234/3965, current 401.962158/3975: elapsed=165933.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 401.796234/3965, current 401.962158/3975: elapsed=165933.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 401.962158
last_received_ts = 401.961578
last_seq = 3975
current_ts = 402.128082
current_received_ts = 402.127502
current_seq = 3985
count = 46
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 401.962158/3975, current 402.128082/3985: elapsed=165941.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 401.962158/3975, current 402.128082/3985: elapsed=165941.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 402.128082
last_received_ts = 402.127502
last_seq = 3985
current_ts = 402.294037
current_received_ts = 402.293457
current_seq = 3995
count = 47
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 402.128082/3985, current 402.294037/3995: elapsed=165941.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 402.128082/3985, current 402.294037/3995: elapsed=165941.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 402.294037
last_received_ts = 402.293457
last_seq = 3995
current_ts = 402.459991
current_received_ts = 402.459381
current_seq = 4005
count = 48
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 402.294037/3995, current 402.459991/4005: elapsed=165951.0us expected=164759.4us +- 823.8us, error 0.7%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 402.294037/3995, current 402.459991/4005: elapsed=165951.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 402.459991
last_received_ts = 402.459381
last_seq = 4005
current_ts = 402.626007
current_received_ts = 402.625397
current_seq = 4015
count = 49
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 402.459991/4005, current 402.626007/4015: elapsed=166019.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 402.459991/4005, current 402.626007/4015: elapsed=166019.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 402.626007
last_received_ts = 402.625397
last_seq = 4015
current_ts = 402.792023
current_received_ts = 402.791443
current_seq = 4025
count = 50
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 402.626007/4015, current 402.792023/4025: elapsed=166012.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 402.626007/4015, current 402.792023/4025: elapsed=166012.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 402.792023
last_received_ts = 402.791443
last_seq = 4025
current_ts = 402.958038
current_received_ts = 402.957428
current_seq = 4035
count = 51
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 402.792023/4025, current 402.958038/4035: elapsed=166020.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 402.792023/4025, current 402.958038/4035: elapsed=166020.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 402.958038
last_received_ts = 402.957428
last_seq = 4035
current_ts = 403.124054
current_received_ts = 403.123444
current_seq = 4045
count = 52
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 402.958038/4035, current 403.124054/4045: elapsed=166019.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 402.958038/4035, current 403.124054/4045: elapsed=166019.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 403.124054
last_received_ts = 403.123444
last_seq = 4045
current_ts = 403.290070
current_received_ts = 403.289459
current_seq = 4055
count = 53
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 403.124054/4045, current 403.290070/4055: elapsed=166013.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 403.124054/4045, current 403.290070/4055: elapsed=166013.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 403.290070
last_received_ts = 403.289459
last_seq = 4055
current_ts = 403.456116
current_received_ts = 403.455505
current_seq = 4065
count = 54
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 403.290070/4055, current 403.456116/4065: elapsed=166031.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 403.290070/4055, current 403.456116/4065: elapsed=166031.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 403.456116
last_received_ts = 403.455505
last_seq = 4065
current_ts = 403.622192
current_received_ts = 403.621582
current_seq = 4075
count = 55
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 403.456116/4065, current 403.622192/4075: elapsed=166081.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 403.456116/4065, current 403.622192/4075: elapsed=166081.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 403.622192
last_received_ts = 403.621582
last_seq = 4075
current_ts = 403.788269
current_received_ts = 403.787659
current_seq = 4085
count = 56
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 403.622192/4075, current 403.788269/4085: elapsed=166080.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 403.622192/4075, current 403.788269/4085: elapsed=166080.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 403.788269
last_received_ts = 403.787659
last_seq = 4085
current_ts = 403.954346
current_received_ts = 403.953766
current_seq = 4095
count = 57
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 403.788269/4085, current 403.954346/4095: elapsed=166091.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 403.788269/4085, current 403.954346/4095: elapsed=166091.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 403.954346
last_received_ts = 403.953766
last_seq = 4095
current_ts = 404.120422
current_received_ts = 404.119843
current_seq = 4105
count = 58
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 403.954346/4095, current 404.120422/4105: elapsed=166082.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 403.954346/4095, current 404.120422/4105: elapsed=166082.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 404.120422
last_received_ts = 404.119843
last_seq = 4105
current_ts = 404.286499
current_received_ts = 404.285889
current_seq = 4115
count = 59
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 404.120422/4105, current 404.286499/4115: elapsed=166077.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 404.120422/4105, current 404.286499/4115: elapsed=166077.0us expected=164759.4us
(kms_flip:7611) DEBUG: name = vblank
last_ts = 404.286499
last_received_ts = 404.285889
last_seq = 4115
current_ts = 404.452606
current_received_ts = 404.452057
current_seq = 4125
count = 60
seq_step = 10
(kms_flip:7611) DEBUG: vblank ts/seq: last 404.286499/4115, current 404.452606/4125: elapsed=166101.0us expected=164759.4us +- 823.8us, error 0.8%
(kms_flip:7611) DEBUG: inconsistent vblank ts/seq: last 404.286499/4115, current 404.452606/4125: elapsed=166101.0us expected=164759.4us
(kms_flip:7611) INFO: Event vblank: expected 613, counted 610, passrate = 40.98%, encoder type 2
(kms_flip:7611) DEBUG: dropped frames, expected 613, counted 610, passrate = 40.98%, encoder type 2
(kms_flip:7611) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1722:
(kms_flip:7611) CRITICAL: Failed assertion: !retried
(kms_flip:7611) igt_core-INFO: Stack trace:
(kms_flip:7611) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:7611) igt_core-INFO:   #1 ../tests/kms_flip.c:1071 run_test_on_crtc_set()
(kms_flip:7611) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:7611) igt_core-INFO:   #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
(kms_flip:7611) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:7611) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:7611) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:7611) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (26.551s)
Dmesg
<6> [393.156728] Console: switching to colour dummy device 80x25
<6> [393.157078] [IGT] kms_flip: executing
<7> [393.165007] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]
<7> [393.165018] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1]
<7> [393.165192] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected
<7> [393.165481] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2]
<7> [393.165485] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2]
<7> [393.165645] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected
<7> [393.165933] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3]
<7> [393.165936] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3]
<7> [393.166079] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected
<7> [393.166391] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1]
<7> [393.166395] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:393:eDP-1]
<7> [393.166869] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00
<7> [393.167196] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000
<7> [393.167315] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000
<7> [393.167427] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000
<7> [393.167585] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz
<5> [393.167594] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [393.167597] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [393.167598] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] DisplayID extension version 0x13, primary use 0x00
<7> [393.167601] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc.
<5> [393.167604] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [393.167606] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD monitor
<5> [393.167611] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [393.167614] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD size 20, SAD count 0
<5> [393.167620] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [393.167644] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] VRR capable: yes
<7> [393.167863] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps
<7> [393.168148] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no
<5> [393.168709] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [393.168713] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [393.168714] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [393.168767] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] probed modes:
<7> [393.168771] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [393.168774] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa
<7> [393.168787] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]
<7> [393.168791] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1]
<7> [393.168930] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected
<7> [393.168941] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2]
<7> [393.168944] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2]
<7> [393.169076] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected
<7> [393.169087] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3]
<7> [393.169090] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3]
<7> [393.169226] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected
<6> [393.169818] [IGT] kms_flip: starting subtest wf_vblank-ts-check
<6> [393.171271] [IGT] kms_flip: starting dynamic subtest A-eDP1
<7> [393.172238] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:431]
<7> [393.172668] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432]
<7> [393.250185] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [393.250483] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [393.250862] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [393.251105] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [393.251370] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [393.251599] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0)
<7> [393.251817] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [393.252024] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [393.252271] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [393.252474] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [393.252704] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [393.252912] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [393.253095] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [393.253306] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [393.253476] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [393.253645] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [393.253808] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [393.253991] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [393.254156] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [393.254347] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [393.254501] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [393.254649] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [393.254793] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [393.254930] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [393.255076] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [393.255243] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [393.255372] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [393.255501] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [393.255654] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [393.255801] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [393.255925] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [393.256058] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [393.256206] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [393.256328] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [393.256440] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [393.256569] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [393.256695] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [393.256803] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [393.256911] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [393.257018] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [393.257126] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0
<7> [393.257307] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [393.257393] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [393.257499] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0
<7> [393.257578] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0
<7> [393.257654] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [393.257729] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [393.257803] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [393.257879] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [393.257982] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0
<7> [393.258105] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [393.258223] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [393.258350] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [393.258475] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [393.258599] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [393.258717] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz
<7> [393.258838] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz
<7> [393.258936] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [393.259029] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [393.259121] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [393.259258] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]
<7> [393.259387] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [393.259505] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [393.259602] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [393.259704] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [393.259797] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [393.259888] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [393.260041] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [393.260142] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [393.260308] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2
<7> [393.261022] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [393.261135] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [393.468610] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [393.469176] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [393.478826] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [393.479240] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [393.479708] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [393.531882] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [393.532237] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [393.540795] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [393.541283] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]
<7> [393.541426] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [393.542832] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [393.543391] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [393.543930] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [393.544369] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [393.544713] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [393.545058] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [393.545414] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [393.545730] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [393.546038] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [393.546381] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [393.546689] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [393.546994] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [393.547329] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [393.547626] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [393.547923] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [393.548230] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [393.548649] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [393.548941] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [393.549261] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [393.549787] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [393.550214] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [393.550740] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [393.551101] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [393.551620] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [393.551931] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [393.552847] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [393.553286] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [393.553617] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [393.553682] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [393.553869] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [393.554271] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000
<7> [393.554610] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [393.554950] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [393.555287] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]
<7> [393.555603] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [393.555936] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [393.556246] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [393.556534] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [393.556796] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)
<7> [393.557074] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [393.557335] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [393.557567] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [393.557793] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [393.558044] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [393.558267] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [393.558467] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [393.558661] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [393.558878] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [393.559076] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [393.559306] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [393.559485] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [393.559646] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [393.559801] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [393.559959] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [393.560112] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [393.560330] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [393.560474] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [393.560617] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [393.560754] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [393.560885] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [393.561038] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [393.561202] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [393.561347] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [393.561473] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [393.561593] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [393.561713] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [393.561829] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [393.561945] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [393.562066] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [393.562199] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [393.562311] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [393.562418] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [393.562525] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [393.562674] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [393.562753] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1
<7> [393.562856] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [393.562931] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [393.563006] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [393.563078] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0
<7> [393.563162] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197
<7> [393.563236] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198
<7> [393.563327] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1
<7> [393.563439] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [393.563551] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [393.563653] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [393.563749] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [393.563840] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [393.563936] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [393.564056] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz
<7> [393.564186] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [393.564290] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [393.564399] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [393.564499] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0
<7> [393.564580] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0
<7> [393.564664] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [393.564755] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [393.564856] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [393.564948] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [393.565037] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [393.565134] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [393.565252] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [393.565357] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64
<7> [393.565454] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [393.565535] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [393.565614] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [393.565701] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [393.565800] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [393.565904] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [393.565993] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [393.566103] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [393.566209] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [393.566312] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [393.566410] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [393.566495] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [393.566577] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [393.566654] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [393.566738] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97
<7> [393.566828] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906
<7> [393.566912] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [393.566996] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [393.567081] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [393.567191] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa
<7> [393.567305] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa
<7> [393.567412] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa
<7> [393.567499] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0
<7> [393.567576] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [393.567659] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [393.567742] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [393.567824] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [393.567908] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [393.568005] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [393.568108] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no
<7> [393.568207] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [393.568303] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [393.568399] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [393.568479] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [393.568557] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [393.568636] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [393.568724] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [393.568812] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [393.568897] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [393.568980] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [393.568969] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [393.569065] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [393.569088] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [393.569171] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [393.569211] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [393.569282] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [393.569338] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [393.569394] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [393.569490] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [393.569587] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [393.569698] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [393.569802] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [393.569883] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [393.569969] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [393.570066] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [393.570177] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:431] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [393.570273] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [393.570347] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [393.570421] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [393.570495] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [393.570569] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [393.570649] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [393.570735] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [393.571049] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [393.571217] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)
<7> [393.571349] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [393.571453] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [393.571547] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [393.571651] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [393.571731] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [393.571808] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [393.571880] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [393.571952] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [393.572024] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [393.572107] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [393.572203] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [393.572300] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [393.572393] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [393.572468] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [393.572547] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [393.572620] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [393.572722] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [393.572910] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [393.572991] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [393.573109] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [393.574116] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]
<7> [393.574228] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [393.576244] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [393.576355] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (465 ms remaining)
<7> [394.042962] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [394.100664] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [394.101122] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on
<7> [394.101583] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [394.137832] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [394.138207] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [394.138546] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [394.139044] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [394.202152] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [394.202295] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [394.202389] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [394.316206] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [394.316639] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [394.316949] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [394.318973] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80
<7> [394.320499] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [394.321317] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [394.322465] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [394.323905] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [394.325010] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK
<7> [394.325396] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [394.326853] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [394.327265] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [394.328097] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [394.328624] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [394.329044] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [394.329470] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 4518
<7> [394.362464] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [394.364092] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [394.364461] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [394.384416] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [394.384959] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [394.385441] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [394.647259] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [394.648358] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [394.679512] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [394.679947] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [394.680333] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [396.882726] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off
<7> [396.883197] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [407.899739] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [407.900163] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [407.900682] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [407.901192] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [407.901719] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [407.902263] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0)
<7> [407.902812] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [407.903430] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [407.904094] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [407.904826] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [407.905514] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [407.906049] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [407.906653] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [407.907246] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [407.907825] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [407.908483] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [407.909064] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [407.909616] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [407.910101] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [407.910603] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [407.911048] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [407.911568] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [407.911958] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [407.912370] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [407.912801] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [407.913199] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [407.913734] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [407.914143] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [407.914658] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [407.915040] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [407.915438] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [407.915792] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [407.916165] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [407.916509] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [407.916803] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [407.917082] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [407.917366] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [407.917690] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [407.917964] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [407.918209] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [407.918478] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0
<7> [407.918867] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [407.919046] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [407.919267] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0
<7> [407.919520] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0
<7> [407.919688] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [407.919861] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [407.920006] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [407.920145] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [407.920330] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0
<7> [407.920535] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [407.920737] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [407.920924] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [407.921128] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [407.921338] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [407.921521] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz
<7> [407.921719] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz
<7> [407.921879] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [407.922027] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [407.922174] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [407.922365] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]
<7> [407.922509] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [407.922647] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [407.922785] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [407.922916] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [407.923046] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [407.923171] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [407.923404] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [407.923533] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [407.923705] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2
<7> [407.923909] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [407.924045] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f
<7> [407.924682] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [407.924812] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [408.132336] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [408.133037] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [408.142731] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [408.143205] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [408.143380] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [408.143890] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [408.143993] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [408.195879] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [408.196291] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [408.199264] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [408.199802] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]
<7> [408.199838] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [408.200589] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [408.201680] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [408.202462] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [408.203246] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [408.203779] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [408.204378] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [408.204838] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [408.205292] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [408.205752] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [408.206196] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [408.206593] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [408.206974] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [408.207427] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [408.207809] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [408.208258] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [408.208633] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [408.209004] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [408.209532] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [408.209882] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [408.210286] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [408.210917] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [408.211513] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [408.212156] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [408.212602] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [408.213168] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [408.213540] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [408.214591] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [408.214980] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [408.215298] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [408.215361] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [408.215539] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [408.215914] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000
<7> [408.216242] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [408.216564] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [408.216863] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]
<7> [408.217156] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [408.217427] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [408.217699] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [408.217944] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [408.218203] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)
<7> [408.218433] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [408.218667] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [408.218871] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [408.219067] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [408.219273] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [408.219454] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [408.219628] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [408.219799] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [408.219961] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [408.220117] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [408.220301] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [408.220455] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [408.220596] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [408.220736] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [408.220870] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [408.221003] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [408.221132] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [408.221274] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [408.221401] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [408.221520] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [408.221640] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [408.221758] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [408.221869] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [408.221980] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [408.222094] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [408.222210] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [408.222324] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [408.222432] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [408.222538] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [408.222659] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [408.222781] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [408.222891] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [408.222994] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [408.223088] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [408.223226] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [408.223314] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1
<7> [408.223411] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [408.223482] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [408.223548] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [408.223614] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0
<7> [408.223679] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197
<7> [408.223742] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198
<7> [408.223824] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1
<7> [408.223920] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [408.224013] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [408.224104] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [408.224188] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [408.224344] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [408.224448] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [408.224556] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz
<7> [408.224648] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [408.224737] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [408.224827] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [408.224943] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0
<7> [408.225047] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0
<7> [408.225153] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [408.225274] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [408.225371] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [408.225456] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [408.225557] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [408.225660] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [408.225762] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [408.225850] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64
<7> [408.225941] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [408.226026] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [408.226112] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [408.226196] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [408.226292] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [408.226379] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [408.226457] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [408.226534] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [408.226610] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [408.226687] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [408.226763] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [408.226839] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [408.226915] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [408.226996] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [408.227084] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97
<7> [408.227178] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906
<7> [408.227267] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [408.227365] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [408.227451] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [408.227532] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa
<7> [408.227624] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa
<7> [408.227714] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa
<7> [408.227796] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0
<7> [408.227877] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [408.227959] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [408.228036] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [408.228111] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [408.228186] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [408.228281] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [408.228386] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no
<7> [408.228470] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [408.228547] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [408.228625] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [408.228702] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [408.228778] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [408.228852] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [408.228929] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [408.229005] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [408.229081] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [408.229156] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [408.229232] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [408.229325] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [408.229427] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [408.229520] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [408.229607] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [408.229698] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [408.229783] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [408.229865] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [408.229946] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [408.230027] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [408.230108] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [408.230203] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:431] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [408.230306] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [408.230394] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [408.230469] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [408.230542] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [408.230616] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [408.230689] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [408.230762] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [408.231028] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [408.231180] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)
<7> [408.231292] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [408.231418] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [408.231533] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [408.231638] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [408.231717] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [408.231801] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [408.231887] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [408.231972] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [408.232048] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [408.232121] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [408.232199] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [408.232281] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [408.232368] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [408.232453] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [408.232525] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [408.232594] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [408.232687] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [408.232853] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [408.232922] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [408.233036] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [408.233230] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [408.233337] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [408.233450] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [408.233599] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [408.234445] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]
<7> [408.234565] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [408.236577] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [408.236682] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (464 ms remaining)
<7> [408.715440] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [408.808637] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [408.809052] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on
<7> [408.809508] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [408.845725] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [408.846306] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [408.846838] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [408.847508] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [409.021913] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [409.022412] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [409.022803] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [409.024948] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80
<7> [409.026478] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [409.027308] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [409.028510] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [409.029851] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [409.031035] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK
<7> [409.031432] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [409.033015] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [409.033409] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [409.034269] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [409.034846] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [409.035254] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [409.035759] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 4518
<7> [409.068469] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [409.070326] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [409.070811] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [409.091398] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [409.092152] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [409.092817] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [409.353966] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [409.354495] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [409.386726] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [409.387403] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [409.388056] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [411.607410] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off
<7> [411.608028] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<6> [419.723671] [IGT] kms_flip: finished subtest A-eDP1, FAIL
Created at 2026-05-11 17:07:30