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

Result: Fail

i915_display_info24 igt_runner24 results24.json results24-xe-load.json guc_logs24.tar i915_display_info_post_exec24 boot24 dmesg24

DetailValue
Duration 9.18 seconds
Hostname
shard-lnl-7
Igt-Version
IGT-Version: 2.3-gfb193977b (x86_64) (Linux: 7.0.0-rc3-lgci-xe-xe-4702-4f823cb4f9faf6611-debug+ x86_64)
Out
Starting dynamic subtest: C-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:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest C-eDP1: FAIL (9.180s)
Subtest flip-vs-expired-vblank: FAIL (31.604s)
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2351 kmstest_set_connector_dpms()
  #2 ../lib/igt_core.c:2961 igt_atexit_handler()
  #3 [erand48_r+0x1d6]
  #4 [exit+0x1e]
  #5 ../lib/igt_core.c:2416 igt_exit()
  #6 [main+0x3f]
  #7 [__libc_init_first+0x8a]
  #8 [__libc_start_main+0x8b]
  #9 [_start+0x25]
Err
Starting dynamic subtest: C-eDP1
(kms_flip:5101) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:5101) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest C-eDP1 failed.
**** DEBUG ****
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.152588
last_received_ts = 353.152069
last_seq = 534
current_ts = 353.169525
current_received_ts = 353.169037
current_seq = 535
count = 349
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 64us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.169525
last_received_ts = 353.169037
last_seq = 535
current_ts = 353.186493
current_received_ts = 353.185974
current_seq = 536
count = 350
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 86us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.186493
last_received_ts = 353.185974
last_seq = 536
current_ts = 353.203430
current_received_ts = 353.202911
current_seq = 537
count = 351
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 62us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.203430
last_received_ts = 353.202911
last_seq = 537
current_ts = 353.220398
current_received_ts = 353.219849
current_seq = 538
count = 352
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 64us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.220398
last_received_ts = 353.219849
last_seq = 538
current_ts = 353.237335
current_received_ts = 353.236786
current_seq = 539
count = 353
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 59us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.237335
last_received_ts = 353.236786
last_seq = 539
current_ts = 353.254272
current_received_ts = 353.253754
current_seq = 540
count = 354
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.254272
last_received_ts = 353.253754
last_seq = 540
current_ts = 353.271240
current_received_ts = 353.270691
current_seq = 541
count = 355
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.271240
last_received_ts = 353.270691
last_seq = 541
current_ts = 353.288177
current_received_ts = 353.287628
current_seq = 542
count = 356
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.288177
last_received_ts = 353.287628
last_seq = 542
current_ts = 353.305115
current_received_ts = 353.304596
current_seq = 543
count = 357
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 69us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.305115
last_received_ts = 353.304596
last_seq = 543
current_ts = 353.322083
current_received_ts = 353.321533
current_seq = 544
count = 358
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 64us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.322083
last_received_ts = 353.321533
last_seq = 544
current_ts = 353.339020
current_received_ts = 353.338440
current_seq = 545
count = 359
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 131us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.339020
last_received_ts = 353.338440
last_seq = 545
current_ts = 353.355988
current_received_ts = 353.355408
current_seq = 546
count = 360
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 130us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.355988
last_received_ts = 353.355408
last_seq = 546
current_ts = 353.372925
current_received_ts = 353.372437
current_seq = 547
count = 361
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 144us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.372925
last_received_ts = 353.372437
last_seq = 547
current_ts = 353.389862
current_received_ts = 353.389374
current_seq = 548
count = 362
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 127us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.389862
last_received_ts = 353.389374
last_seq = 548
current_ts = 353.406830
current_received_ts = 353.406311
current_seq = 549
count = 363
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 92us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.406830
last_received_ts = 353.406311
last_seq = 549
current_ts = 353.423767
current_received_ts = 353.423248
current_seq = 550
count = 364
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 106us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.423767
last_received_ts = 353.423248
last_seq = 550
current_ts = 353.440735
current_received_ts = 353.440186
current_seq = 551
count = 365
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 67us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.440735
last_received_ts = 353.440186
last_seq = 551
current_ts = 353.457672
current_received_ts = 353.457153
current_seq = 552
count = 366
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 69us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.457672
last_received_ts = 353.457153
last_seq = 552
current_ts = 353.474640
current_received_ts = 353.474121
current_seq = 553
count = 367
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 65us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.474640
last_received_ts = 353.474121
last_seq = 553
current_ts = 353.491577
current_received_ts = 353.491058
current_seq = 554
count = 368
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 67us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.491577
last_received_ts = 353.491058
last_seq = 554
current_ts = 353.508514
current_received_ts = 353.508026
current_seq = 555
count = 369
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.508514
last_received_ts = 353.508026
last_seq = 555
current_ts = 353.525482
current_received_ts = 353.524933
current_seq = 556
count = 370
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 65us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.525482
last_received_ts = 353.524933
last_seq = 556
current_ts = 353.542419
current_received_ts = 353.541870
current_seq = 557
count = 371
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 62us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.542419
last_received_ts = 353.541870
last_seq = 557
current_ts = 353.559357
current_received_ts = 353.558807
current_seq = 558
count = 372
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 75us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.559357
last_received_ts = 353.558807
last_seq = 558
current_ts = 353.576324
current_received_ts = 353.575745
current_seq = 559
count = 373
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 62us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.576324
last_received_ts = 353.575745
last_seq = 559
current_ts = 353.593262
current_received_ts = 353.592682
current_seq = 560
count = 374
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 60us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.593262
last_received_ts = 353.592682
last_seq = 560
current_ts = 353.610229
current_received_ts = 353.609680
current_seq = 561
count = 375
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 67us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.610229
last_received_ts = 353.609680
last_seq = 561
current_ts = 353.627167
current_received_ts = 353.626587
current_seq = 562
count = 376
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.627167
last_received_ts = 353.626587
last_seq = 562
current_ts = 353.644104
current_received_ts = 353.643555
current_seq = 563
count = 377
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 60us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.644104
last_received_ts = 353.643555
last_seq = 563
current_ts = 353.661072
current_received_ts = 353.660492
current_seq = 564
count = 378
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.661072
last_received_ts = 353.660492
last_seq = 564
current_ts = 353.678009
current_received_ts = 353.677490
current_seq = 565
count = 379
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 134us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.678009
last_received_ts = 353.677490
last_seq = 565
current_ts = 353.694977
current_received_ts = 353.694458
current_seq = 566
count = 380
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 128us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.694977
last_received_ts = 353.694458
last_seq = 566
current_ts = 353.711914
current_received_ts = 353.711426
current_seq = 567
count = 381
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 140us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.711914
last_received_ts = 353.711426
last_seq = 567
current_ts = 353.728882
current_received_ts = 353.728363
current_seq = 568
count = 382
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 133us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.728882
last_received_ts = 353.728363
last_seq = 568
current_ts = 353.745819
current_received_ts = 353.745300
current_seq = 569
count = 383
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 66us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.745819
last_received_ts = 353.745300
last_seq = 569
current_ts = 353.762756
current_received_ts = 353.762268
current_seq = 570
count = 384
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 123us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.762756
last_received_ts = 353.762268
last_seq = 570
current_ts = 353.779724
current_received_ts = 353.779175
current_seq = 571
count = 385
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.779724
last_received_ts = 353.779175
last_seq = 571
current_ts = 353.796661
current_received_ts = 353.796143
current_seq = 572
count = 386
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 61us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.796661
last_received_ts = 353.796143
last_seq = 572
current_ts = 353.813629
current_received_ts = 353.813049
current_seq = 573
count = 387
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 64us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.813629
last_received_ts = 353.813049
last_seq = 573
current_ts = 353.830566
current_received_ts = 353.829987
current_seq = 574
count = 388
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 64us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.830566
last_received_ts = 353.829987
last_seq = 574
current_ts = 353.847504
current_received_ts = 353.846924
current_seq = 575
count = 389
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 76us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.847504
last_received_ts = 353.846924
last_seq = 575
current_ts = 353.864471
current_received_ts = 353.863861
current_seq = 576
count = 390
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.864471
last_received_ts = 353.863861
last_seq = 576
current_ts = 353.881409
current_received_ts = 353.880859
current_seq = 577
count = 391
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 59us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.881409
last_received_ts = 353.880859
last_seq = 577
current_ts = 353.898376
current_received_ts = 353.897797
current_seq = 578
count = 392
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 66us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.898376
last_received_ts = 353.897797
last_seq = 578
current_ts = 353.915314
current_received_ts = 353.914734
current_seq = 579
count = 393
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.915314
last_received_ts = 353.914734
last_seq = 579
current_ts = 353.932251
current_received_ts = 353.931702
current_seq = 580
count = 394
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 60us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.932251
last_received_ts = 353.931702
last_seq = 580
current_ts = 353.949219
current_received_ts = 353.948639
current_seq = 581
count = 395
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 61us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.949219
last_received_ts = 353.948639
last_seq = 581
current_ts = 353.966156
current_received_ts = 353.965576
current_seq = 582
count = 396
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 61us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.966156
last_received_ts = 353.965576
last_seq = 582
current_ts = 353.983124
current_received_ts = 353.982574
current_seq = 583
count = 397
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 353.983124
last_received_ts = 353.982574
last_seq = 583
current_ts = 354.000061
current_received_ts = 353.999512
current_seq = 584
count = 398
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 60us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.000061
last_received_ts = 353.999512
last_seq = 584
current_ts = 354.016998
current_received_ts = 354.016479
current_seq = 585
count = 399
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 109us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.016998
last_received_ts = 354.016479
last_seq = 585
current_ts = 354.033966
current_received_ts = 354.033417
current_seq = 586
count = 400
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 124us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.033966
last_received_ts = 354.033417
last_seq = 586
current_ts = 354.050903
current_received_ts = 354.050415
current_seq = 587
count = 401
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.050903
last_received_ts = 354.050415
last_seq = 587
current_ts = 354.067871
current_received_ts = 354.067322
current_seq = 588
count = 402
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 127us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.067871
last_received_ts = 354.067322
last_seq = 588
current_ts = 354.084808
current_received_ts = 354.084259
current_seq = 589
count = 403
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 117us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.084808
last_received_ts = 354.084259
last_seq = 589
current_ts = 354.101746
current_received_ts = 354.101166
current_seq = 590
count = 404
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.101746
last_received_ts = 354.101166
last_seq = 590
current_ts = 354.118713
current_received_ts = 354.118164
current_seq = 591
count = 405
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 72us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.118713
last_received_ts = 354.118164
last_seq = 591
current_ts = 354.135620
current_received_ts = 354.135071
current_seq = 592
count = 406
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.135620
last_received_ts = 354.135071
last_seq = 592
current_ts = 354.152557
current_received_ts = 354.151978
current_seq = 593
count = 407
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 66us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.152557
last_received_ts = 354.151978
last_seq = 593
current_ts = 354.169464
current_received_ts = 354.168945
current_seq = 594
count = 408
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 89us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.169464
last_received_ts = 354.168945
last_seq = 594
current_ts = 354.186371
current_received_ts = 354.185852
current_seq = 595
count = 409
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 61us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.186371
last_received_ts = 354.185852
last_seq = 595
current_ts = 354.203278
current_received_ts = 354.202759
current_seq = 596
count = 410
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.203278
last_received_ts = 354.202759
last_seq = 596
current_ts = 354.220215
current_received_ts = 354.219666
current_seq = 597
count = 411
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 62us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.220215
last_received_ts = 354.219666
last_seq = 597
current_ts = 354.237122
current_received_ts = 354.236603
current_seq = 598
count = 412
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 62us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.237122
last_received_ts = 354.236603
last_seq = 598
current_ts = 354.254028
current_received_ts = 354.253510
current_seq = 599
count = 413
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 61us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.254028
last_received_ts = 354.253510
last_seq = 599
current_ts = 354.270935
current_received_ts = 354.270386
current_seq = 600
count = 414
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 66us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.270935
last_received_ts = 354.270386
last_seq = 600
current_ts = 354.287872
current_received_ts = 354.287354
current_seq = 601
count = 415
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 66us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.287872
last_received_ts = 354.287354
last_seq = 601
current_ts = 354.304779
current_received_ts = 354.304260
current_seq = 602
count = 416
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 99us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.304779
last_received_ts = 354.304260
last_seq = 602
current_ts = 354.321686
current_received_ts = 354.321198
current_seq = 603
count = 417
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 65us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.321686
last_received_ts = 354.321198
last_seq = 603
current_ts = 354.338623
current_received_ts = 354.338074
current_seq = 604
count = 418
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.338623
last_received_ts = 354.338074
last_seq = 604
current_ts = 354.355530
current_received_ts = 354.355042
current_seq = 605
count = 419
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 68us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.355530
last_received_ts = 354.355042
last_seq = 605
current_ts = 354.372437
current_received_ts = 354.371918
current_seq = 606
count = 420
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 85us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.372437
last_received_ts = 354.371918
last_seq = 606
current_ts = 354.389343
current_received_ts = 354.388824
current_seq = 607
count = 421
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 65us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.389343
last_received_ts = 354.388824
last_seq = 607
current_ts = 354.406281
current_received_ts = 354.405792
current_seq = 608
count = 422
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 75us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.406281
last_received_ts = 354.405792
last_seq = 608
current_ts = 354.423187
current_received_ts = 354.422668
current_seq = 609
count = 423
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 69us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.423187
last_received_ts = 354.422668
last_seq = 609
current_ts = 354.440094
current_received_ts = 354.439575
current_seq = 610
count = 424
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 65us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.440094
last_received_ts = 354.439575
last_seq = 610
current_ts = 354.457031
current_received_ts = 354.456451
current_seq = 611
count = 425
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 70us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.457031
last_received_ts = 354.456451
last_seq = 611
current_ts = 354.473938
current_received_ts = 354.473450
current_seq = 612
count = 426
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 143us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.473938
last_received_ts = 354.473450
last_seq = 612
current_ts = 354.490845
current_received_ts = 354.490295
current_seq = 613
count = 427
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 72us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.490845
last_received_ts = 354.490295
last_seq = 613
current_ts = 354.507751
current_received_ts = 354.507263
current_seq = 614
count = 428
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 103us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.507751
last_received_ts = 354.507263
last_seq = 614
current_ts = 354.524689
current_received_ts = 354.524170
current_seq = 615
count = 429
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 72us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.524689
last_received_ts = 354.524170
last_seq = 615
current_ts = 354.541595
current_received_ts = 354.541077
current_seq = 616
count = 430
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 60us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.541595
last_received_ts = 354.541077
last_seq = 616
current_ts = 354.558502
current_received_ts = 354.557983
current_seq = 617
count = 431
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 100us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.558502
last_received_ts = 354.557983
last_seq = 617
current_ts = 354.575409
current_received_ts = 354.574921
current_seq = 618
count = 432
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.575409
last_received_ts = 354.574921
last_seq = 618
current_ts = 354.592346
current_received_ts = 354.591797
current_seq = 619
count = 433
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 46us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.592346
last_received_ts = 354.591797
last_seq = 619
current_ts = 354.609253
current_received_ts = 354.608734
current_seq = 620
count = 434
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 61us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.609253
last_received_ts = 354.608734
last_seq = 620
current_ts = 354.626160
current_received_ts = 354.625641
current_seq = 621
count = 435
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.626160
last_received_ts = 354.625641
last_seq = 621
current_ts = 354.643066
current_received_ts = 354.642578
current_seq = 622
count = 436
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 69us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.643066
last_received_ts = 354.642578
last_seq = 622
current_ts = 354.660004
current_received_ts = 354.659485
current_seq = 623
count = 437
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 136us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.660004
last_received_ts = 354.659485
last_seq = 623
current_ts = 354.676910
current_received_ts = 354.676422
current_seq = 624
count = 438
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 135us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.676910
last_received_ts = 354.676422
last_seq = 624
current_ts = 354.693817
current_received_ts = 354.693298
current_seq = 625
count = 439
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 102us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.693817
last_received_ts = 354.693298
last_seq = 625
current_ts = 354.710724
current_received_ts = 354.710205
current_seq = 626
count = 440
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 135us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.710724
last_received_ts = 354.710205
last_seq = 626
current_ts = 354.727661
current_received_ts = 354.727142
current_seq = 627
count = 441
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 66us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.727661
last_received_ts = 354.727142
last_seq = 627
current_ts = 354.744568
current_received_ts = 354.744049
current_seq = 628
count = 442
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 65us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.744568
last_received_ts = 354.744049
last_seq = 628
current_ts = 354.761475
current_received_ts = 354.760986
current_seq = 629
count = 443
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 89us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.761475
last_received_ts = 354.760986
last_seq = 629
current_ts = 354.778412
current_received_ts = 354.777893
current_seq = 630
count = 444
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 61us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.778412
last_received_ts = 354.777893
last_seq = 630
current_ts = 354.795319
current_received_ts = 354.794800
current_seq = 631
count = 445
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 73us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.795319
last_received_ts = 354.794800
last_seq = 631
current_ts = 354.812225
current_received_ts = 354.811707
current_seq = 632
count = 446
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.812225
last_received_ts = 354.811707
last_seq = 632
current_ts = 354.829132
current_received_ts = 354.828583
current_seq = 633
count = 447
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 69us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.829132
last_received_ts = 354.828583
last_seq = 633
current_ts = 354.846069
current_received_ts = 354.845520
current_seq = 634
count = 448
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 62us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.846069
last_received_ts = 354.845520
last_seq = 634
current_ts = 354.862976
current_received_ts = 354.862457
current_seq = 635
count = 449
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 134us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.862976
last_received_ts = 354.862457
last_seq = 635
current_ts = 354.879883
current_received_ts = 354.879364
current_seq = 636
count = 450
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 129us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.879883
last_received_ts = 354.879364
last_seq = 636
current_ts = 354.896790
current_received_ts = 354.896271
current_seq = 637
count = 451
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 112us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.896790
last_received_ts = 354.896271
last_seq = 637
current_ts = 354.913727
current_received_ts = 354.913177
current_seq = 638
count = 452
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.913727
last_received_ts = 354.913177
last_seq = 638
current_ts = 354.930634
current_received_ts = 354.930145
current_seq = 639
count = 453
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 71us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.930634
last_received_ts = 354.930145
last_seq = 639
current_ts = 354.947540
current_received_ts = 354.947052
current_seq = 640
count = 454
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 65us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.947540
last_received_ts = 354.947052
last_seq = 640
current_ts = 354.964447
current_received_ts = 354.963959
current_seq = 641
count = 455
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 94us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.964447
last_received_ts = 354.963959
last_seq = 641
current_ts = 354.981384
current_received_ts = 354.980865
current_seq = 642
count = 456
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 64us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.981384
last_received_ts = 354.980865
last_seq = 642
current_ts = 354.998291
current_received_ts = 354.997772
current_seq = 643
count = 457
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 65us
(kms_flip:5101) DEBUG: name = flip
last_ts = 354.998291
last_received_ts = 354.997772
last_seq = 643
current_ts = 355.015198
current_received_ts = 355.014679
current_seq = 644
count = 458
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 61us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.015198
last_received_ts = 355.014679
last_seq = 644
current_ts = 355.032135
current_received_ts = 355.031586
current_seq = 645
count = 459
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.032135
last_received_ts = 355.031586
last_seq = 645
current_ts = 355.049042
current_received_ts = 355.048523
current_seq = 646
count = 460
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 63us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.049042
last_received_ts = 355.048523
last_seq = 646
current_ts = 355.065948
current_received_ts = 355.065430
current_seq = 647
count = 461
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 64us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.065948
last_received_ts = 355.065430
last_seq = 647
current_ts = 355.082855
current_received_ts = 355.082367
current_seq = 648
count = 462
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 141us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.082855
last_received_ts = 355.082367
last_seq = 648
current_ts = 355.099792
current_received_ts = 355.099274
current_seq = 649
count = 463
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 102us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.099792
last_received_ts = 355.099274
last_seq = 649
current_ts = 355.116699
current_received_ts = 355.116180
current_seq = 650
count = 464
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 71us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.116699
last_received_ts = 355.116180
last_seq = 650
current_ts = 355.133606
current_received_ts = 355.133087
current_seq = 651
count = 465
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 53us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.133606
last_received_ts = 355.133087
last_seq = 651
current_ts = 355.150482
current_received_ts = 355.149811
current_seq = 652
count = 466
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 71us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.150482
last_received_ts = 355.149811
last_seq = 652
current_ts = 355.167358
current_received_ts = 355.166656
current_seq = 653
count = 467
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 38us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.167358
last_received_ts = 355.166656
last_seq = 653
current_ts = 355.184235
current_received_ts = 355.183533
current_seq = 654
count = 468
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 48us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.184235
last_received_ts = 355.183533
last_seq = 654
current_ts = 355.201111
current_received_ts = 355.200317
current_seq = 655
count = 469
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 39us
(kms_flip:5101) DEBUG: name = flip
last_ts = 355.201111
last_received_ts = 355.200317
last_seq = 655
current_ts = 355.218018
current_received_ts = 355.217224
current_seq = 656
count = 470
seq_step = 1
(kms_flip:5101) DEBUG: Vblank took 712us
(kms_flip:5101) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:5101) CRITICAL: Failed assertion: end - start < 500
(kms_flip:5101) igt_core-INFO: Stack trace:
(kms_flip:5101) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:5101) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:5101) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:5101) igt_core-INFO:   #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043()
(kms_flip:5101) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:5101) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:5101) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:5101) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-eDP1: FAIL (9.180s)
Subtest flip-vs-expired-vblank: FAIL (31.604s)
(kms_flip:5101) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2351:
(kms_flip:5101) igt_kms-CRITICAL: Failed assertion: found_it
(kms_flip:5101) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
(kms_flip:5101) igt_kms-CRITICAL: DPMS property not found on 392
Dmesg
<6> [404.922392] [IGT] kms_flip: starting dynamic subtest C-eDP1
<7> [404.934422] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430]
<7> [404.934805] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:431]
<7> [404.935851] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [404.936015] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [404.936146] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [405.010507] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]
<7> [405.010744] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [405.011089] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [405.011548] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]
<7> [405.011704] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [405.012003] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [405.012239] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [405.012460] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [405.012676] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] 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> [405.012909] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [405.013114] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [405.013316] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [405.013508] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [405.013691] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [405.013933] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [405.014111] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [405.014281] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [405.014445] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [405.014602] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [405.014771] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [405.014926] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [405.015072] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [405.015217] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [405.015381] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [405.015541] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [405.015680] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [405.015833] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [405.015986] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [405.016140] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [405.016271] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [405.016395] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [405.016518] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [405.016637] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [405.016760] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [405.016880] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [405.017008] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [405.017141] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [405.017261] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [405.017377] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [405.017493] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [405.017608] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [405.017717] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe B] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [405.017841] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe B] fastset requirement not met, forcing full modeset
<7> [405.017962] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:269:pipe B] releasing DPLL 0
<7> [405.018111] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [405.018210] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:269:pipe B] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [405.018340] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:263:cursor B] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0
<7> [405.018452] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:269:pipe B] min cdclk: 173855 kHz -> 0 kHz
<7> [405.018566] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [405.018675] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [405.018788] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [405.018923] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:269:pipe B] enable: no [modeset]
<7> [405.019041] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:153:plane 1B] fb: [NOFB], visible: no
<7> [405.019157] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:183:plane 2B] fb: [NOFB], visible: no
<7> [405.019269] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:213:plane 3B] fb: [NOFB], visible: no
<7> [405.019370] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:243:plane 4B] fb: [NOFB], visible: no
<7> [405.019470] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:253:plane 5B] fb: [NOFB], visible: no
<7> [405.019568] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:263:cursor B] fb: [NOFB], visible: no
<7> [405.019826] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [405.019942] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [405.227823] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 0
<7> [405.228492] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe B
<7> [405.239269] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power off
<7> [405.239651] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [405.240081] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [405.291157] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [405.291484] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:269:pipe B]
<7> [405.292344] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [405.292879] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [405.293227] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [405.293091] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short
<7> [405.293586] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A]
<7> [405.293815] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A]
<7> [405.293903] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1]
<7> [405.294131] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A]
<7> [405.294354] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B]
<7> [405.294569] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C]
<7> [405.294819] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2]
<7> [405.295051] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A]
<7> [405.295271] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B]
<7> [405.295537] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C]
<7> [405.295793] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3]
<7> [405.296083] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A]
<7> [405.296341] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B]
<7> [405.296606] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C]
<7> [405.296907] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1]
<7> [405.297245] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [405.297490] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [405.297775] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [405.298342] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_B
<7> [405.298734] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x2 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [405.299176] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [405.299571] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:269:pipe B]
<7> [405.299934] 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> [405.300298] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [405.300569] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [405.301438] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:388:pipe C]
<7> [405.301859] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:388:pipe C]
<7> [405.301936] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:392:eDP-1]
<7> [405.302140] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:392:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [405.302562] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:391:DDI A/PHY A][CRTC:388:pipe C] 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> [405.302953] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [405.303332] xe 0000:00:02.0: [drm:intel_psr_compute_config [xe]] PSR2 not supported in transcoder C
<7> [405.303615] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:388:pipe C] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [405.304015] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:391:DDI A/PHY A] [CRTC:388:pipe C]
<7> [405.304344] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.enable (expected no, found yes)
<7> [405.304639] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.active (expected no, found yes)
<7> [405.304974] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)
<7> [405.305287] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in lane_count (expected 0, found 4)
<7> [405.305556] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] 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> [405.305851] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [405.306127] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [405.306358] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [405.306573] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [405.306817] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [405.307033] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [405.307227] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [405.307417] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [405.307625] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [405.307839] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [405.308015] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [405.308187] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [405.308379] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [405.308564] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [405.308766] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [405.308926] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [405.309078] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [405.309226] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [405.309367] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [405.309506] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [405.309646] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [405.309833] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [405.309976] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [405.310112] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [405.310246] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [405.310391] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [405.310522] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [405.310645] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [405.310835] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [405.310961] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [405.311079] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [405.311192] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [405.311301] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [405.311410] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:388:pipe C] fastset requirement not met, forcing full modeset
<7> [405.311544] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no
<7> [405.311649] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:388:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4
<7> [405.311810] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:272:plane 1C] ddb ( 0 - 0) -> ( 0 - 2003), size 0 -> 2003
<7> [405.311904] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:382:cursor C] ddb ( 0 - 0) -> (2003 - 2048), size 0 -> 45
<7> [405.311986] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:272:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [405.312063] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:272:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0
<7> [405.312140] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:272:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197
<7> [405.312215] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:272:plane 1C] 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> [405.312303] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:388:pipe C] data rate 1390840 num active planes 1
<7> [405.312417] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [405.312521] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [405.312624] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [405.312740] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [405.312842] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [405.312954] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:388:pipe C] min cdclk: 0 kHz -> 173855 kHz
<7> [405.313080] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [405.313178] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [405.313266] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [405.313368] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:388:pipe C] allocated DPLL 0
<7> [405.313456] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:388:pipe C] reserving DPLL 0
<7> [405.313540] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:388:pipe C] enable: yes [modeset]
<7> [405.313627] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [405.313735] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: C, pipe bpp: 30, dithering: 0
<7> [405.313842] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [405.313944] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [405.314027] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [405.314103] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [405.314177] 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> [405.314250] 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> [405.314323] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [405.314394] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [405.314465] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: disabled, panel replay: disabled, selective fetch: disabled
<7> [405.314535] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0
<7> [405.314604] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [405.314682] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 2, length 8
<7> [405.314780] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [405.314873] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [405.314963] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [405.315039] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [405.315114] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [405.315188] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [405.315264] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [405.315339] 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> [405.315416] 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> [405.315490] 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> [405.315560] 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> [405.315630] 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> [405.315722] 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> [405.315818] 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> [405.315912] 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> [405.315997] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855
<7> [405.316068] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [405.316139] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [405.316209] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [405.316280] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [405.316350] 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> [405.316420] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [405.316489] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [405.316564] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [405.316641] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [405.316731] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [405.316809] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [405.316884] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [405.316959] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [405.317035] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [405.317109] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x40000000 gamma_enable: 0 csc_enable: 0
<7> [405.317184] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 256 entries
<7> [405.317259] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [405.317330] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [405.317398] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [405.317468] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [405.317537] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [405.317607] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [405.317684] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [405.317760] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [405.317834] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [405.317907] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [405.317980] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [405.318048] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:272:plane 1C] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [405.318118] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [405.318189] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [405.318263] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:302:plane 2C] fb: [NOFB], visible: no
<7> [405.318341] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:332:plane 3C] fb: [NOFB], visible: no
<7> [405.318416] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:362:plane 4C] fb: [NOFB], visible: no
<7> [405.318492] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:372:plane 5C] fb: [NOFB], visible: no
<7> [405.318566] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:382:cursor C] fb: [NOFB], visible: no
<7> [405.318968] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [405.319099] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_C
<7> [405.319226] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0x8a000000)
<7> [405.319316] 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> [405.319399] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [405.319487] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [405.319573] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A]
<7> [405.319645] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1]
<7> [405.319733] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A]
<7> [405.319804] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B]
<7> [405.319872] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C]
<7> [405.319939] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2]
<7> [405.320005] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A]
<7> [405.320070] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B]
<7> [405.320135] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C]
<7> [405.320196] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3]
<7> [405.320253] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A]
<7> [405.320311] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B]
<7> [405.320369] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C]
<7> [405.320446] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xd
<7> [405.320599] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [405.320706] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [405.321768] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:388:pipe C]
<7> [405.321884] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [405.323821] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power on
<7> [405.323906] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power cycle (468 ms remaining)
<7> [405.331625] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [405.331830] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long
<7> [405.331930] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [405.332057] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A]
<7> [405.796026] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [405.847081] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [405.847384] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power on
<7> [405.847694] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [405.884083] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [405.884647] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long
<7> [405.885108] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [405.885779] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A]
<7> [406.055994] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [406.056336] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on
<7> [406.056678] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [406.058657] 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> [406.060156] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [406.060854] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [406.061993] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [406.063461] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [406.064643] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Clock recovery OK
<7> [406.065120] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [406.066893] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [406.067391] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [406.068536] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe C
<7> [406.069101] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [406.069532] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe C
<7> [406.069990] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 192000
<7> [406.071765] xe 0000:00:02.0: [drm:intel_fbc_update [xe]] reserved 14745600 bytes of contiguous stolen space for FBC, limit: 2
<7> [406.072127] xe 0000:00:02.0: [drm:intel_fbc_update [xe]] Enabling FBC on [PLANE:272:plane 1C]
<7> [406.085983] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR1
<7> [406.087429] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1]
<7> [406.087815] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:388:pipe C]
<7> [408.609715] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD off
<7> [408.610048] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<6> [414.102914] [IGT] kms_flip: finished subtest C-eDP1, FAIL
<6> [414.105660] [IGT] kms_flip: finished subtest flip-vs-expired-vblank, FAIL
<7> [414.123049] xe 0000:00:02.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:430] from all active usage due to RMFB ioctl
<7> [414.123143] xe 0000:00:02.0: [drm:atomic_remove_fb] Disabling [PLANE:272:plane 1C] because [FB:430] is removed
<7> [414.123239] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:272:plane 1C] ddb ( 0 - 2003) -> ( 0 - 0), size 2003 -> 0
<7> [414.123465] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:272:plane 1C] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [414.123621] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:272:plane 1C] lines 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [414.123772] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:272:plane 1C] blocks 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [414.123987] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:272:plane 1C] 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> [414.124164] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:388:pipe C] data rate 0 num active planes 0
<7> [414.124389] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [414.124608] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [414.124842] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [414.125064] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [414.125348] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [414.126317] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR1
<7> [414.135776] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on
<7> [414.135985] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f
<7> [414.148515] xe 0000:00:02.0: [drm:__intel_fbc_disable [xe]] Disabling FBC on [PLANE:272:plane 1C]
<7> [414.171420] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:392:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [414.171814] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:391:DDI A/PHY A][CRTC:150: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> [414.172199] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [414.172522] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [414.172856] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:391:DDI A/PHY A] [CRTC:150:pipe A]
<7> [414.173250] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [414.173577] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [414.173865] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [414.174169] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [414.174490] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150: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> [414.174752] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [414.174996] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [414.175256] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [414.175523] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [414.175759] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [414.175990] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [414.176426] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [414.176651] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [414.176853] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [414.177038] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [414.177234] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [414.177399] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [414.177564] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [414.177719] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [414.177898] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [414.178066] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [414.178241] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [414.178383] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [414.178523] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [414.178677] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [414.178833] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [414.178970] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [414.179108] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [414.179235] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [414.179356] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [414.179477] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [414.179595] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [414.179727] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [414.179863] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [414.179981] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [414.180102] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [414.180211] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [414.180315] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [414.180420] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset
<7> [414.180523] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.enable (expected yes, found no)
<7> [414.180627] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.active (expected yes, found no)
<7> [414.180730] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1)
<7> [414.180832] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in lane_count (expected 4, found 0)
<7> [414.180935] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] 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> [414.181036] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [414.181156] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [414.181252] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [414.181345] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [414.181436] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [414.181528] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [414.181615] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [414.181701] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [414.181787] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [414.181873] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [414.181962] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [414.182070] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [414.182161] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [414.182250] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [414.182339] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [414.182423] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [414.182498] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [414.182573] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [414.182647] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [414.182722] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [414.182797] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [414.182871] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [414.182945] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [414.183163] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [414.183270] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [414.183365] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [414.183455] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [414.183532] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [414.183608] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [414.183678] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [414.183752] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [414.183827] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [414.183903] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:388:pipe C] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [414.183978] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:388:pipe C] fastset requirement not met, forcing full modeset
<7> [414.184073] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:388:pipe C] releasing DPLL 0
<7> [414.184212] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xd -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [414.184299] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x4 -> 0x1
<7> [414.184385] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:388:pipe C] dbuf slices 0xc -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x4 -> 0x1
<7> [414.184468] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [414.184531] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [414.184588] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [414.184646] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0
<7> [414.184704] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87
<7> [414.184761] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88
<7> [414.184818] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:382:cursor C] ddb (2003 - 2048) -> ( 0 - 0), size 45 -> 0
<7> [414.184884] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 1390840 num active planes 1
<7> [414.184982] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [414.185116] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [414.185225] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [414.185325] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [414.185414] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [414.185503] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [414.185587] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:388:pipe C] min cdclk: 173855 kHz -> 0 kHz
<7> [414.185699] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated DPLL 0
<7> [414.185788] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving DPLL 0
<7> [414.185895] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset]
<7> [414.186023] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [414.186129] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [414.186230] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [414.186322] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [414.186403] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [414.186484] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [414.186564] 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> [414.186644] 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> [414.186725] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [414.186807] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [414.186885] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [414.186962] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0
<7> [414.187073] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [414.187169] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [414.187262] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [414.187354] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [414.187442] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [414.187519] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [414.187595] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [414.187671] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [414.187747] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [414.187821] 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> [414.187891] 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> [414.187966] 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> [414.188057] 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> [414.188149] 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> [414.188241] 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> [414.188332] 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> [414.188412] 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> [414.188499] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855
<7> [414.188593] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [414.188685] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [414.188777] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [414.188854] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [414.188924] 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> [414.189023] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [414.189114] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [414.189206] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [414.189298] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [414.189389] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [414.189467] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [414.189543] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [414.189619] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [414.189695] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [414.189771] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [414.189846] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [414.189917] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [414.190020] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [414.190110] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [414.190199] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [414.190288] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [414.190376] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [414.190452] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [414.190531] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [414.190619] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [414.190707] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [414.190795] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [414.190873] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [FB:393] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [414.190979] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [414.191072] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [414.191166] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no
<7> [414.191258] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no
<7> [414.191346] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no
<7> [414.191422] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no
<7> [414.191497] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no
<7> [414.191573] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:388:pipe C] enable: no [modeset]
<7> [414.191648] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:272:plane 1C] fb: [NOFB], visible: no
<7> [414.191723] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:302:plane 2C] fb: [NOFB], visible: no
<7> [414.191793] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:332:plane 3C] fb: [NOFB], visible: no
<7> [414.191861] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:362:plane 4C] fb: [NOFB], visible: no
<7> [414.191948] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:372:plane 5C] fb: [NOFB], visible: no
<7> [414.192038] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:382:cursor C] fb: [NOFB], visible: no
<7> [414.192210] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [414.192389] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0x88000000)
<7> [414.192792] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [414.192904] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [414.398869] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 0
<7> [414.399460] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe C
<7> [414.420073] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power off
<7> [414.420570] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [414.421083] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [414.473362] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [414.474118] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short
<7> [414.479168] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [414.480663] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A]
<7> [414.480688] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x4, on? 1) for [CRTC:388:pipe C]
<7> [414.482284] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [414.482822] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [414.483401] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A]
<7> [414.483824] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1]
<7> [414.484215] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A]
<7> [414.484616] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B]
<7> [414.484973] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C]
<7> [414.485370] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2]
<7> [414.485704] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A]
<7> [414.486022] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B]
<7> [414.486378] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C]
<7> [414.486698] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3]
<7> [414.486985] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A]
<7> [414.487331] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B]
<7> [414.487607] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C]
<7> [414.488182] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [414.488677] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [414.488978] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [414.489368] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [414.491117] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:150:pipe A]
<7> [414.491580] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [414.494063] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power on
<7> [414.494391] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power cycle (485 ms remaining)
<7> [414.512208] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [414.512751] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long
<7> [414.513268] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [414.513872] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A]
<7> [414.974976] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [415.025988] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [415.026345] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power on
<7> [415.026590] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [415.063220] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [415.063784] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long
<7> [415.064242] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [415.064918] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A]
<7> [415.239014] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [415.239353] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on
<7> [415.239616] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [415.241885] 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> [415.243365] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [415.244083] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [415.245161] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [415.246412] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [415.247515] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Clock recovery OK
<7> [415.247918] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [415.249455] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [415.249885] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [415.250816] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [415.251304] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [415.251711] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [415.252111] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 192000
<7> [415.268202] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [415.269939] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1]
<7> [415.270324] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A]
<7> [415.273160] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_C
<7> [415.273542] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0xa8000000)
<7> [415.274436] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [415.274806] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:388:pipe C]
<7> [415.275195] xe 0000:00:02.0: [drm:drm_client_dev_restore] fbdev: ret=0
<6> [415.276746] [IGT] kms_flip: exiting, ret=98
<7> [415.292151] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [415.292287] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [415.292378] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
Created at 2026-03-12 17:16:47