Results for igt@kms_flip@flip-vs-expired-vblank@a-edp1

Result: Fail

i915_display_info23 igt_runner23 results23.json results23-xe-load.json guc_logs23.tar i915_display_info_post_exec23 boot23 dmesg23

DetailValue
Duration 6.27 seconds
Hostname 
shard-lnl-7
Igt-Version 
IGT-Version: 2.4-g9a1fafa7f (x86_64) (Linux: 7.1.0-rc1-lgci-xe-xe-4940-b6f6b69b2dffa9ad1-debug+ x86_64)
Out 
Using IGT_SRANDOM=1777330242 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 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 (6.270s)
Err 
Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
(kms_flip:6007) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:6007) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.191711
last_received_ts = 278.191132
last_seq = 541
current_ts = 278.208374
current_received_ts = 278.207764
current_seq = 542
count = 168
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 60us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.208374
last_received_ts = 278.207764
last_seq = 542
current_ts = 278.225037
current_received_ts = 278.224426
current_seq = 543
count = 169
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 108us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.225037
last_received_ts = 278.224426
last_seq = 543
current_ts = 278.241699
current_received_ts = 278.241150
current_seq = 544
count = 170
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 46us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.241699
last_received_ts = 278.241150
last_seq = 544
current_ts = 278.258362
current_received_ts = 278.257782
current_seq = 545
count = 171
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.258362
last_received_ts = 278.257782
last_seq = 545
current_ts = 278.275024
current_received_ts = 278.274384
current_seq = 546
count = 172
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 70us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.275024
last_received_ts = 278.274384
last_seq = 546
current_ts = 278.291687
current_received_ts = 278.291107
current_seq = 547
count = 173
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.291687
last_received_ts = 278.291107
last_seq = 547
current_ts = 278.308350
current_received_ts = 278.307770
current_seq = 548
count = 174
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 114us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.308350
last_received_ts = 278.307770
last_seq = 548
current_ts = 278.325012
current_received_ts = 278.324432
current_seq = 549
count = 175
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 103us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.325012
last_received_ts = 278.324432
last_seq = 549
current_ts = 278.341675
current_received_ts = 278.341125
current_seq = 550
count = 176
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.341675
last_received_ts = 278.341125
last_seq = 550
current_ts = 278.358337
current_received_ts = 278.357727
current_seq = 551
count = 177
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 67us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.358337
last_received_ts = 278.357727
last_seq = 551
current_ts = 278.375000
current_received_ts = 278.374420
current_seq = 552
count = 178
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 113us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.375000
last_received_ts = 278.374420
last_seq = 552
current_ts = 278.391663
current_received_ts = 278.391083
current_seq = 553
count = 179
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.391663
last_received_ts = 278.391083
last_seq = 553
current_ts = 278.408325
current_received_ts = 278.407745
current_seq = 554
count = 180
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.408325
last_received_ts = 278.407745
last_seq = 554
current_ts = 278.424988
current_received_ts = 278.424408
current_seq = 555
count = 181
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 128us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.424988
last_received_ts = 278.424408
last_seq = 555
current_ts = 278.441650
current_received_ts = 278.441071
current_seq = 556
count = 182
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.441650
last_received_ts = 278.441071
last_seq = 556
current_ts = 278.458313
current_received_ts = 278.457733
current_seq = 557
count = 183
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.458313
last_received_ts = 278.457733
last_seq = 557
current_ts = 278.474976
current_received_ts = 278.474396
current_seq = 558
count = 184
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 117us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.474976
last_received_ts = 278.474396
last_seq = 558
current_ts = 278.491638
current_received_ts = 278.491058
current_seq = 559
count = 185
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.491638
last_received_ts = 278.491058
last_seq = 559
current_ts = 278.508301
current_received_ts = 278.507721
current_seq = 560
count = 186
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.508301
last_received_ts = 278.507721
last_seq = 560
current_ts = 278.524963
current_received_ts = 278.524384
current_seq = 561
count = 187
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 106us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.524963
last_received_ts = 278.524384
last_seq = 561
current_ts = 278.541626
current_received_ts = 278.541077
current_seq = 562
count = 188
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.541626
last_received_ts = 278.541077
last_seq = 562
current_ts = 278.558289
current_received_ts = 278.557709
current_seq = 563
count = 189
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.558289
last_received_ts = 278.557709
last_seq = 563
current_ts = 278.574951
current_received_ts = 278.574371
current_seq = 564
count = 190
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 112us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.574951
last_received_ts = 278.574371
last_seq = 564
current_ts = 278.591614
current_received_ts = 278.591064
current_seq = 565
count = 191
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.591614
last_received_ts = 278.591064
last_seq = 565
current_ts = 278.608276
current_received_ts = 278.607697
current_seq = 566
count = 192
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.608276
last_received_ts = 278.607697
last_seq = 566
current_ts = 278.624939
current_received_ts = 278.624359
current_seq = 567
count = 193
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 103us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.624939
last_received_ts = 278.624359
last_seq = 567
current_ts = 278.641602
current_received_ts = 278.641052
current_seq = 568
count = 194
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.641602
last_received_ts = 278.641052
last_seq = 568
current_ts = 278.658264
current_received_ts = 278.657715
current_seq = 569
count = 195
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.658264
last_received_ts = 278.657715
last_seq = 569
current_ts = 278.674927
current_received_ts = 278.674347
current_seq = 570
count = 196
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 98us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.674927
last_received_ts = 278.674347
last_seq = 570
current_ts = 278.691589
current_received_ts = 278.691040
current_seq = 571
count = 197
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 60us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.691589
last_received_ts = 278.691040
last_seq = 571
current_ts = 278.708252
current_received_ts = 278.707672
current_seq = 572
count = 198
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.708252
last_received_ts = 278.707672
last_seq = 572
current_ts = 278.724915
current_received_ts = 278.724365
current_seq = 573
count = 199
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 112us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.724915
last_received_ts = 278.724365
last_seq = 573
current_ts = 278.741577
current_received_ts = 278.741028
current_seq = 574
count = 200
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 60us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.741577
last_received_ts = 278.741028
last_seq = 574
current_ts = 278.758240
current_received_ts = 278.757690
current_seq = 575
count = 201
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.758240
last_received_ts = 278.757690
last_seq = 575
current_ts = 278.774902
current_received_ts = 278.774323
current_seq = 576
count = 202
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 110us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.774902
last_received_ts = 278.774323
last_seq = 576
current_ts = 278.791565
current_received_ts = 278.790985
current_seq = 577
count = 203
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.791565
last_received_ts = 278.790985
last_seq = 577
current_ts = 278.808228
current_received_ts = 278.807678
current_seq = 578
count = 204
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.808228
last_received_ts = 278.807678
last_seq = 578
current_ts = 278.824890
current_received_ts = 278.824341
current_seq = 579
count = 205
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.824890
last_received_ts = 278.824341
last_seq = 579
current_ts = 278.841553
current_received_ts = 278.841003
current_seq = 580
count = 206
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.841553
last_received_ts = 278.841003
last_seq = 580
current_ts = 278.858215
current_received_ts = 278.857666
current_seq = 581
count = 207
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 114us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.858215
last_received_ts = 278.857666
last_seq = 581
current_ts = 278.874878
current_received_ts = 278.874329
current_seq = 582
count = 208
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.874878
last_received_ts = 278.874329
last_seq = 582
current_ts = 278.891541
current_received_ts = 278.890961
current_seq = 583
count = 209
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 82us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.891541
last_received_ts = 278.890961
last_seq = 583
current_ts = 278.908203
current_received_ts = 278.907654
current_seq = 584
count = 210
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.908203
last_received_ts = 278.907654
last_seq = 584
current_ts = 278.924866
current_received_ts = 278.924316
current_seq = 585
count = 211
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 65us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.924866
last_received_ts = 278.924316
last_seq = 585
current_ts = 278.941528
current_received_ts = 278.940979
current_seq = 586
count = 212
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 82us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.941528
last_received_ts = 278.940979
last_seq = 586
current_ts = 278.958191
current_received_ts = 278.957642
current_seq = 587
count = 213
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 117us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.958191
last_received_ts = 278.957642
last_seq = 587
current_ts = 278.974854
current_received_ts = 278.974274
current_seq = 588
count = 214
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 91us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.974854
last_received_ts = 278.974274
last_seq = 588
current_ts = 278.991516
current_received_ts = 278.990967
current_seq = 589
count = 215
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 79us
(kms_flip:6007) DEBUG: name = flip
last_ts = 278.991516
last_received_ts = 278.990967
last_seq = 589
current_ts = 279.008179
current_received_ts = 279.007629
current_seq = 590
count = 216
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 70us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.008179
last_received_ts = 279.007629
last_seq = 590
current_ts = 279.024841
current_received_ts = 279.024261
current_seq = 591
count = 217
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 99us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.024841
last_received_ts = 279.024261
last_seq = 591
current_ts = 279.041504
current_received_ts = 279.040955
current_seq = 592
count = 218
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 82us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.041504
last_received_ts = 279.040955
last_seq = 592
current_ts = 279.058167
current_received_ts = 279.057587
current_seq = 593
count = 219
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 65us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.058167
last_received_ts = 279.057587
last_seq = 593
current_ts = 279.074829
current_received_ts = 279.074158
current_seq = 594
count = 220
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.074829
last_received_ts = 279.074158
last_seq = 594
current_ts = 279.091522
current_received_ts = 279.090942
current_seq = 595
count = 221
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 76us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.091522
last_received_ts = 279.090942
last_seq = 595
current_ts = 279.108154
current_received_ts = 279.107605
current_seq = 596
count = 222
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 123us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.108154
last_received_ts = 279.107605
last_seq = 596
current_ts = 279.124847
current_received_ts = 279.124268
current_seq = 597
count = 223
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 63us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.124847
last_received_ts = 279.124268
last_seq = 597
current_ts = 279.141510
current_received_ts = 279.140900
current_seq = 598
count = 224
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.141510
last_received_ts = 279.140900
last_seq = 598
current_ts = 279.158142
current_received_ts = 279.157593
current_seq = 599
count = 225
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.158142
last_received_ts = 279.157593
last_seq = 599
current_ts = 279.174835
current_received_ts = 279.174225
current_seq = 600
count = 226
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 94us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.174835
last_received_ts = 279.174225
last_seq = 600
current_ts = 279.191498
current_received_ts = 279.190918
current_seq = 601
count = 227
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 66us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.191498
last_received_ts = 279.190918
last_seq = 601
current_ts = 279.208130
current_received_ts = 279.207581
current_seq = 602
count = 228
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.208130
last_received_ts = 279.207581
last_seq = 602
current_ts = 279.224823
current_received_ts = 279.224274
current_seq = 603
count = 229
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 121us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.224823
last_received_ts = 279.224274
last_seq = 603
current_ts = 279.241486
current_received_ts = 279.240906
current_seq = 604
count = 230
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.241486
last_received_ts = 279.240906
last_seq = 604
current_ts = 279.258148
current_received_ts = 279.257568
current_seq = 605
count = 231
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 49us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.258148
last_received_ts = 279.257568
last_seq = 605
current_ts = 279.274811
current_received_ts = 279.274200
current_seq = 606
count = 232
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 110us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.274811
last_received_ts = 279.274200
last_seq = 606
current_ts = 279.291473
current_received_ts = 279.290894
current_seq = 607
count = 233
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 140us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.291473
last_received_ts = 279.290894
last_seq = 607
current_ts = 279.308136
current_received_ts = 279.307556
current_seq = 608
count = 234
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.308136
last_received_ts = 279.307556
last_seq = 608
current_ts = 279.324799
current_received_ts = 279.324188
current_seq = 609
count = 235
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 109us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.324799
last_received_ts = 279.324188
last_seq = 609
current_ts = 279.341461
current_received_ts = 279.340881
current_seq = 610
count = 236
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.341461
last_received_ts = 279.340881
last_seq = 610
current_ts = 279.358124
current_received_ts = 279.357544
current_seq = 611
count = 237
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.358124
last_received_ts = 279.357544
last_seq = 611
current_ts = 279.374786
current_received_ts = 279.374207
current_seq = 612
count = 238
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 122us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.374786
last_received_ts = 279.374207
last_seq = 612
current_ts = 279.391449
current_received_ts = 279.390869
current_seq = 613
count = 239
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 140us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.391449
last_received_ts = 279.390869
last_seq = 613
current_ts = 279.408112
current_received_ts = 279.407532
current_seq = 614
count = 240
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 112us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.408112
last_received_ts = 279.407532
last_seq = 614
current_ts = 279.424774
current_received_ts = 279.424164
current_seq = 615
count = 241
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.424774
last_received_ts = 279.424164
last_seq = 615
current_ts = 279.441437
current_received_ts = 279.440857
current_seq = 616
count = 242
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.441437
last_received_ts = 279.440857
last_seq = 616
current_ts = 279.458099
current_received_ts = 279.457520
current_seq = 617
count = 243
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 113us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.458099
last_received_ts = 279.457520
last_seq = 617
current_ts = 279.474762
current_received_ts = 279.474152
current_seq = 618
count = 244
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.474762
last_received_ts = 279.474152
last_seq = 618
current_ts = 279.491425
current_received_ts = 279.490845
current_seq = 619
count = 245
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.491425
last_received_ts = 279.490845
last_seq = 619
current_ts = 279.508087
current_received_ts = 279.507507
current_seq = 620
count = 246
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 67us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.508087
last_received_ts = 279.507507
last_seq = 620
current_ts = 279.524750
current_received_ts = 279.524384
current_seq = 621
count = 247
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 53us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.524750
last_received_ts = 279.524384
last_seq = 621
current_ts = 279.541412
current_received_ts = 279.540833
current_seq = 622
count = 248
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.541412
last_received_ts = 279.540833
last_seq = 622
current_ts = 279.558075
current_received_ts = 279.557495
current_seq = 623
count = 249
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 115us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.558075
last_received_ts = 279.557495
last_seq = 623
current_ts = 279.574738
current_received_ts = 279.574188
current_seq = 624
count = 250
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 136us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.574738
last_received_ts = 279.574188
last_seq = 624
current_ts = 279.591400
current_received_ts = 279.590820
current_seq = 625
count = 251
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 117us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.591400
last_received_ts = 279.590820
last_seq = 625
current_ts = 279.608063
current_received_ts = 279.607483
current_seq = 626
count = 252
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 100us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.608063
last_received_ts = 279.607483
last_seq = 626
current_ts = 279.624725
current_received_ts = 279.624176
current_seq = 627
count = 253
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.624725
last_received_ts = 279.624176
last_seq = 627
current_ts = 279.641388
current_received_ts = 279.640839
current_seq = 628
count = 254
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 64us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.641388
last_received_ts = 279.640839
last_seq = 628
current_ts = 279.658051
current_received_ts = 279.657471
current_seq = 629
count = 255
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 123us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.658051
last_received_ts = 279.657471
last_seq = 629
current_ts = 279.674713
current_received_ts = 279.674133
current_seq = 630
count = 256
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.674713
last_received_ts = 279.674133
last_seq = 630
current_ts = 279.691376
current_received_ts = 279.690796
current_seq = 631
count = 257
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.691376
last_received_ts = 279.690796
last_seq = 631
current_ts = 279.708038
current_received_ts = 279.707458
current_seq = 632
count = 258
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 124us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.708038
last_received_ts = 279.707458
last_seq = 632
current_ts = 279.724701
current_received_ts = 279.724152
current_seq = 633
count = 259
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.724701
last_received_ts = 279.724152
last_seq = 633
current_ts = 279.741364
current_received_ts = 279.740784
current_seq = 634
count = 260
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 133us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.741364
last_received_ts = 279.740784
last_seq = 634
current_ts = 279.758026
current_received_ts = 279.757446
current_seq = 635
count = 261
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 102us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.758026
last_received_ts = 279.757446
last_seq = 635
current_ts = 279.774689
current_received_ts = 279.774109
current_seq = 636
count = 262
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.774689
last_received_ts = 279.774109
last_seq = 636
current_ts = 279.791351
current_received_ts = 279.790771
current_seq = 637
count = 263
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.791351
last_received_ts = 279.790771
last_seq = 637
current_ts = 279.808014
current_received_ts = 279.807434
current_seq = 638
count = 264
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 103us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.808014
last_received_ts = 279.807434
last_seq = 638
current_ts = 279.824677
current_received_ts = 279.824158
current_seq = 639
count = 265
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.824677
last_received_ts = 279.824158
last_seq = 639
current_ts = 279.841339
current_received_ts = 279.840759
current_seq = 640
count = 266
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.841339
last_received_ts = 279.840759
last_seq = 640
current_ts = 279.858002
current_received_ts = 279.857422
current_seq = 641
count = 267
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 129us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.858002
last_received_ts = 279.857422
last_seq = 641
current_ts = 279.874664
current_received_ts = 279.874084
current_seq = 642
count = 268
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.874664
last_received_ts = 279.874084
last_seq = 642
current_ts = 279.891327
current_received_ts = 279.890778
current_seq = 643
count = 269
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 63us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.891327
last_received_ts = 279.890778
last_seq = 643
current_ts = 279.907990
current_received_ts = 279.907440
current_seq = 644
count = 270
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 104us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.907990
last_received_ts = 279.907440
last_seq = 644
current_ts = 279.924652
current_received_ts = 279.924103
current_seq = 645
count = 271
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.924652
last_received_ts = 279.924103
last_seq = 645
current_ts = 279.941315
current_received_ts = 279.940765
current_seq = 646
count = 272
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 128us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.941315
last_received_ts = 279.940765
last_seq = 646
current_ts = 279.957977
current_received_ts = 279.957428
current_seq = 647
count = 273
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 113us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.957977
last_received_ts = 279.957428
last_seq = 647
current_ts = 279.974640
current_received_ts = 279.974091
current_seq = 648
count = 274
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.974640
last_received_ts = 279.974091
last_seq = 648
current_ts = 279.991302
current_received_ts = 279.990723
current_seq = 649
count = 275
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 58us
(kms_flip:6007) DEBUG: name = flip
last_ts = 279.991302
last_received_ts = 279.990723
last_seq = 649
current_ts = 280.007965
current_received_ts = 280.007385
current_seq = 650
count = 276
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 114us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.007965
last_received_ts = 280.007385
last_seq = 650
current_ts = 280.024628
current_received_ts = 280.024078
current_seq = 651
count = 277
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.024628
last_received_ts = 280.024078
last_seq = 651
current_ts = 280.041290
current_received_ts = 280.040741
current_seq = 652
count = 278
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.041290
last_received_ts = 280.040741
last_seq = 652
current_ts = 280.057953
current_received_ts = 280.057404
current_seq = 653
count = 279
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 100us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.057953
last_received_ts = 280.057404
last_seq = 653
current_ts = 280.074615
current_received_ts = 280.074066
current_seq = 654
count = 280
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 63us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.074615
last_received_ts = 280.074066
last_seq = 654
current_ts = 280.091278
current_received_ts = 280.090729
current_seq = 655
count = 281
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.091278
last_received_ts = 280.090729
last_seq = 655
current_ts = 280.107941
current_received_ts = 280.107361
current_seq = 656
count = 282
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 97us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.107941
last_received_ts = 280.107361
last_seq = 656
current_ts = 280.124603
current_received_ts = 280.124054
current_seq = 657
count = 283
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 62us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.124603
last_received_ts = 280.124054
last_seq = 657
current_ts = 280.141296
current_received_ts = 280.140717
current_seq = 658
count = 284
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.141296
last_received_ts = 280.140717
last_seq = 658
current_ts = 280.157928
current_received_ts = 280.157349
current_seq = 659
count = 285
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 110us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.157928
last_received_ts = 280.157349
last_seq = 659
current_ts = 280.174591
current_received_ts = 280.174042
current_seq = 660
count = 286
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 61us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.174591
last_received_ts = 280.174042
last_seq = 660
current_ts = 280.191284
current_received_ts = 280.190674
current_seq = 661
count = 287
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 59us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.191284
last_received_ts = 280.190674
last_seq = 661
current_ts = 280.207947
current_received_ts = 280.207367
current_seq = 662
count = 288
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 97us
(kms_flip:6007) DEBUG: name = flip
last_ts = 280.207947
last_received_ts = 280.207367
last_seq = 662
current_ts = 280.224609
current_received_ts = 280.224030
current_seq = 663
count = 289
seq_step = 1
(kms_flip:6007) DEBUG: Vblank took 649us
(kms_flip:6007) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:6007) CRITICAL: Failed assertion: end - start < 500
(kms_flip:6007) igt_core-INFO: Stack trace:
(kms_flip:6007) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:6007) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:6007) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:6007) igt_core-INFO:   #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
(kms_flip:6007) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:6007) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:6007) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:6007) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (6.270s)
Dmesg
<6> [274.469137] Console: switching to colour dummy device 80x25
<6> [274.469533] [IGT] kms_flip: executing
<7> [274.475056] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]
<7> [274.475066] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1]
<7> [274.475258] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected
<7> [274.475513] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2]
<7> [274.475516] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2]
<7> [274.475644] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected
<7> [274.475848] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3]
<7> [274.475850] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3]
<7> [274.475966] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected
<7> [274.476275] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1]
<7> [274.476279] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:393:eDP-1]
<7> [274.476747] 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> [274.477068] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000
<7> [274.477226] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000
<7> [274.477337] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000
<7> [274.477455] 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> [274.477459] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [274.477461] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [274.477463] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] DisplayID extension version 0x13, primary use 0x00
<7> [274.477465] 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> [274.477467] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [274.477469] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD monitor
<5> [274.477471] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [274.477472] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD size 20, SAD count 0
<5> [274.477475] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [274.477487] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] VRR capable: yes
<7> [274.477593] 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> [274.477684] 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> [274.477992] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [274.477994] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [274.477996] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [274.478038] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] probed modes:
<7> [274.478040] 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> [274.478044] 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> [274.478054] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]
<7> [274.478057] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1]
<7> [274.478210] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected
<7> [274.478220] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2]
<7> [274.478222] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2]
<7> [274.478354] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected
<7> [274.478363] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3]
<7> [274.478366] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3]
<7> [274.478494] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected
<6> [274.478994] [IGT] kms_flip: starting subtest flip-vs-expired-vblank
<6> [274.480432] [IGT] kms_flip: starting dynamic subtest A-eDP1
<7> [274.481341] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430]
<7> [274.481760] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432]
<7> [274.563960] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [274.564252] 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> [274.564627] 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> [274.564958] 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> [274.565310] 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> [274.565629] 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> [274.565936] 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> [274.566321] 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> [274.566608] 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> [274.566907] 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> [274.567203] 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> [274.567460] 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> [274.567735] 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> [274.567981] 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> [274.568244] 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> [274.568489] 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> [274.568756] 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> [274.568986] 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> [274.569246] 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> [274.569453] 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> [274.569656] 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> [274.569856] 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> [274.570083] 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> [274.570277] 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> [274.570478] 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> [274.570653] 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> [274.570826] 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> [274.571015] 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> [274.571200] 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> [274.571379] 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> [274.571556] 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> [274.571733] 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> [274.571892] 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> [274.572039] 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> [274.572201] 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> [274.572366] 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> [274.572529] 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> [274.572665] 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> [274.572805] 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> [274.572941] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [274.573079] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0
<7> [274.573280] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [274.573383] 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> [274.573515] 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> [274.573611] 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> [274.573704] 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> [274.573794] 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> [274.573883] 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> [274.573967] 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> [274.574095] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0
<7> [274.574229] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [274.574356] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [274.574478] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [274.574600] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [274.574716] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [274.574833] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz
<7> [274.574976] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz
<7> [274.575107] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [274.575232] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [274.575352] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [274.575482] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]
<7> [274.575602] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [274.575710] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [274.575814] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [274.575916] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [274.576015] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [274.576124] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [274.576293] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [274.577025] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [274.577182] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2
<7> [274.577904] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [274.578179] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [274.784236] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [274.784774] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [274.794422] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [274.794679] 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> [274.794934] 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> [274.847281] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [274.847638] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [274.855988] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [274.856383] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]
<7> [274.856438] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [274.857774] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [274.858192] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [274.858617] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [274.858895] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [274.859192] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [274.859498] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [274.859746] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [274.859974] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [274.860225] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [274.860454] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [274.860679] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [274.860919] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [274.861182] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [274.861416] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [274.861653] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [274.861869] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [274.862169] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [274.862389] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [274.862600] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [274.862986] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [274.863316] 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> [274.863673] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [274.863983] 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> [274.864320] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [274.864558] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [274.865260] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [274.865561] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [274.865808] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [274.865868] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [274.866012] 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> [274.866379] 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> [274.866654] 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> [274.866952] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [274.867272] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]
<7> [274.867563] 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> [274.867896] 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> [274.868217] 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> [274.868498] 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> [274.868821] 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> [274.869104] 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> [274.869362] 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> [274.869610] 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> [274.869855] 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> [274.870095] 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> [274.870314] 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> [274.870527] 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> [274.870741] 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> [274.870946] 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> [274.871163] 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> [274.871349] 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> [274.871542] 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> [274.871723] 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> [274.871899] 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> [274.872108] 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> [274.872292] 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> [274.872461] 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> [274.872616] 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> [274.872778] 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> [274.872940] 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> [274.873107] 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> [274.873262] 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> [274.873411] 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> [274.873551] 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> [274.873689] 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> [274.873827] 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> [274.873968] 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> [274.874119] 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> [274.874269] 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> [274.874401] 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> [274.874522] 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> [274.874639] 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> [274.874755] 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> [274.874874] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [274.875040] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [274.875179] 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> [274.875310] 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> [274.875395] 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> [274.875474] 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> [274.875550] 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> [274.875626] 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> [274.875701] 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> [274.875796] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1
<7> [274.875924] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [274.876043] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [274.876214] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [274.876329] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [274.876435] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [274.876541] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [274.876656] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz
<7> [274.876765] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [274.876861] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [274.876954] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [274.877064] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0
<7> [274.877169] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0
<7> [274.877274] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [274.877385] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [274.877484] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [274.877570] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [274.877654] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [274.877736] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [274.877819] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [274.877897] 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> [274.877975] 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> [274.878059] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [274.878159] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [274.878259] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [274.878357] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [274.878440] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [274.878524] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [274.878621] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [274.878712] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [274.878796] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [274.878879] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [274.878965] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [274.879071] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [274.879182] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [274.879294] 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> [274.879401] 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> [274.879487] 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> [274.879568] 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> [274.879646] 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> [274.879724] 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> [274.879802] 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> [274.879882] 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> [274.879984] 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> [274.880090] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [274.880191] 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> [274.880294] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [274.880393] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [274.880490] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [274.880587] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [274.880676] 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> [274.880753] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [274.880826] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [274.880900] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [274.880984] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [274.881077] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [274.881188] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [274.881296] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [274.881402] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [274.881500] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [274.881588] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [274.881667] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [274.881750] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [274.881828] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [274.881908] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [274.881987] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [274.882067] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [274.882172] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [274.882269] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [274.882366] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [274.882476] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [274.882625] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [274.882754] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [274.882879] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [274.882978] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [274.883093] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [274.883106] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [274.883204] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [274.883280] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [274.883300] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [274.883395] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [274.883409] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [274.883490] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [274.883955] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [274.884223] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [274.884405] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [274.884598] 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> [274.884744] 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> [274.884874] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [274.884996] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [274.885132] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [274.885240] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [274.885337] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [274.885425] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [274.885509] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [274.885584] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [274.885658] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [274.885737] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [274.885812] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [274.885891] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [274.885979] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [274.886076] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [274.886158] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [274.886259] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [274.886444] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [274.886527] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [274.886650] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [274.887548] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [274.887672] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [274.887769] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [274.887909] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [274.887974] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]
<7> [274.888101] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [274.890059] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [274.890149] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining)
<7> [275.360268] 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> [275.462066] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [275.462397] 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> [275.462665] 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> [275.481094] 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> [275.481075] 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> [275.481155] 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> [275.499024] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [275.499472] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [275.499894] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [275.500325] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [275.669281] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [275.669631] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [275.669909] 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> [275.671973] 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> [275.673467] 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> [275.674192] 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> [275.675276] 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> [275.676574] 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> [275.677570] 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> [275.677873] 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> [275.679295] 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> [275.679623] 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> [275.680410] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [275.680902] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [275.681274] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [275.681686] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 4518
<7> [275.697855] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [275.699573] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [275.699942] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [278.232137] 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> [278.232481] 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> [280.565313] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [280.565711] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [280.566003] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<6> [280.750952] [IGT] kms_flip: finished subtest A-eDP1, FAIL
Created at 2026-04-27 23:20:08