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

Result: Fail

i915_display_info18 igt_runner18 results18.json results18-xe-load.json guc_logs18.tar i915_display_info_post_exec18 boot18 dmesg18

DetailValue
Duration 9.85 seconds
Hostname 
shard-lnl-3
Igt-Version 
IGT-Version: 2.4-g17f08dbb3 (x86_64) (Linux: 7.0.0-lgci-xe-xe-4921-898b5aa235c5b269d-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:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest C-eDP1: FAIL (9.848s)
Subtest flip-vs-expired-vblank: FAIL (32.298s)
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2352 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:2365) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2365) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest C-eDP1 failed.
**** DEBUG ****
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.351387
last_received_ts = 123.350830
last_seq = 591
current_ts = 123.368065
current_received_ts = 123.367493
current_seq = 592
count = 382
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.368065
last_received_ts = 123.367493
last_seq = 592
current_ts = 123.384727
current_received_ts = 123.384148
current_seq = 593
count = 383
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 63us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.384727
last_received_ts = 123.384148
last_seq = 593
current_ts = 123.401390
current_received_ts = 123.400803
current_seq = 594
count = 384
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.401390
last_received_ts = 123.400803
last_seq = 594
current_ts = 123.418053
current_received_ts = 123.417427
current_seq = 595
count = 385
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.418053
last_received_ts = 123.417427
last_seq = 595
current_ts = 123.434715
current_received_ts = 123.434158
current_seq = 596
count = 386
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 72us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.434715
last_received_ts = 123.434158
last_seq = 596
current_ts = 123.451385
current_received_ts = 123.450821
current_seq = 597
count = 387
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.451385
last_received_ts = 123.450821
last_seq = 597
current_ts = 123.468048
current_received_ts = 123.467499
current_seq = 598
count = 388
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 137us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.468048
last_received_ts = 123.467499
last_seq = 598
current_ts = 123.484711
current_received_ts = 123.484154
current_seq = 599
count = 389
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.484711
last_received_ts = 123.484154
last_seq = 599
current_ts = 123.501381
current_received_ts = 123.500793
current_seq = 600
count = 390
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.501381
last_received_ts = 123.500793
last_seq = 600
current_ts = 123.518036
current_received_ts = 123.517479
current_seq = 601
count = 391
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 128us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.518036
last_received_ts = 123.517479
last_seq = 601
current_ts = 123.534706
current_received_ts = 123.534126
current_seq = 602
count = 392
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.534706
last_received_ts = 123.534126
last_seq = 602
current_ts = 123.551376
current_received_ts = 123.550804
current_seq = 603
count = 393
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.551376
last_received_ts = 123.550804
last_seq = 603
current_ts = 123.568039
current_received_ts = 123.567329
current_seq = 604
count = 394
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.568039
last_received_ts = 123.567329
last_seq = 604
current_ts = 123.584702
current_received_ts = 123.584106
current_seq = 605
count = 395
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.584702
last_received_ts = 123.584106
last_seq = 605
current_ts = 123.601372
current_received_ts = 123.600822
current_seq = 606
count = 396
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.601372
last_received_ts = 123.600822
last_seq = 606
current_ts = 123.618027
current_received_ts = 123.617485
current_seq = 607
count = 397
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 130us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.618027
last_received_ts = 123.617485
last_seq = 607
current_ts = 123.634689
current_received_ts = 123.634125
current_seq = 608
count = 398
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.634689
last_received_ts = 123.634125
last_seq = 608
current_ts = 123.651360
current_received_ts = 123.650810
current_seq = 609
count = 399
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.651360
last_received_ts = 123.650810
last_seq = 609
current_ts = 123.668022
current_received_ts = 123.667419
current_seq = 610
count = 400
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 74us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.668022
last_received_ts = 123.667419
last_seq = 610
current_ts = 123.684685
current_received_ts = 123.684128
current_seq = 611
count = 401
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.684685
last_received_ts = 123.684128
last_seq = 611
current_ts = 123.701355
current_received_ts = 123.700768
current_seq = 612
count = 402
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 76us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.701355
last_received_ts = 123.700768
last_seq = 612
current_ts = 123.718018
current_received_ts = 123.717468
current_seq = 613
count = 403
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 126us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.718018
last_received_ts = 123.717468
last_seq = 613
current_ts = 123.734680
current_received_ts = 123.734116
current_seq = 614
count = 404
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.734680
last_received_ts = 123.734116
last_seq = 614
current_ts = 123.751343
current_received_ts = 123.750786
current_seq = 615
count = 405
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.751343
last_received_ts = 123.750786
last_seq = 615
current_ts = 123.768013
current_received_ts = 123.767456
current_seq = 616
count = 406
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 142us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.768013
last_received_ts = 123.767456
last_seq = 616
current_ts = 123.784676
current_received_ts = 123.784088
current_seq = 617
count = 407
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 95us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.784676
last_received_ts = 123.784088
last_seq = 617
current_ts = 123.801338
current_received_ts = 123.800774
current_seq = 618
count = 408
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 77us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.801338
last_received_ts = 123.800774
last_seq = 618
current_ts = 123.818001
current_received_ts = 123.817429
current_seq = 619
count = 409
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 141us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.818001
last_received_ts = 123.817429
last_seq = 619
current_ts = 123.834671
current_received_ts = 123.834106
current_seq = 620
count = 410
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.834671
last_received_ts = 123.834106
last_seq = 620
current_ts = 123.851334
current_received_ts = 123.850769
current_seq = 621
count = 411
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.851334
last_received_ts = 123.850769
last_seq = 621
current_ts = 123.867996
current_received_ts = 123.867432
current_seq = 622
count = 412
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 138us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.867996
last_received_ts = 123.867432
last_seq = 622
current_ts = 123.884659
current_received_ts = 123.884117
current_seq = 623
count = 413
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.884659
last_received_ts = 123.884117
last_seq = 623
current_ts = 123.901329
current_received_ts = 123.900787
current_seq = 624
count = 414
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.901329
last_received_ts = 123.900787
last_seq = 624
current_ts = 123.917992
current_received_ts = 123.917435
current_seq = 625
count = 415
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 126us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.917992
last_received_ts = 123.917435
last_seq = 625
current_ts = 123.934654
current_received_ts = 123.934113
current_seq = 626
count = 416
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 55us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.934654
last_received_ts = 123.934113
last_seq = 626
current_ts = 123.951324
current_received_ts = 123.950768
current_seq = 627
count = 417
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.951324
last_received_ts = 123.950768
last_seq = 627
current_ts = 123.967987
current_received_ts = 123.967430
current_seq = 628
count = 418
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 128us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.967987
last_received_ts = 123.967430
last_seq = 628
current_ts = 123.984650
current_received_ts = 123.984100
current_seq = 629
count = 419
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 82us
(kms_flip:2365) DEBUG: name = flip
last_ts = 123.984650
last_received_ts = 123.984100
last_seq = 629
current_ts = 124.001312
current_received_ts = 124.000755
current_seq = 630
count = 420
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 85us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.001312
last_received_ts = 124.000755
last_seq = 630
current_ts = 124.017982
current_received_ts = 124.017433
current_seq = 631
count = 421
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 128us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.017982
last_received_ts = 124.017433
last_seq = 631
current_ts = 124.034645
current_received_ts = 124.034088
current_seq = 632
count = 422
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.034645
last_received_ts = 124.034088
last_seq = 632
current_ts = 124.051315
current_received_ts = 124.050766
current_seq = 633
count = 423
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.051315
last_received_ts = 124.050766
last_seq = 633
current_ts = 124.067978
current_received_ts = 124.067421
current_seq = 634
count = 424
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 136us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.067978
last_received_ts = 124.067421
last_seq = 634
current_ts = 124.084641
current_received_ts = 124.084084
current_seq = 635
count = 425
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.084641
last_received_ts = 124.084084
last_seq = 635
current_ts = 124.101303
current_received_ts = 124.100777
current_seq = 636
count = 426
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.101303
last_received_ts = 124.100777
last_seq = 636
current_ts = 124.117966
current_received_ts = 124.117439
current_seq = 637
count = 427
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 137us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.117966
last_received_ts = 124.117439
last_seq = 637
current_ts = 124.134644
current_received_ts = 124.134094
current_seq = 638
count = 428
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 72us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.134644
last_received_ts = 124.134094
last_seq = 638
current_ts = 124.151306
current_received_ts = 124.150742
current_seq = 639
count = 429
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.151306
last_received_ts = 124.150742
last_seq = 639
current_ts = 124.167961
current_received_ts = 124.167397
current_seq = 640
count = 430
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 139us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.167961
last_received_ts = 124.167397
last_seq = 640
current_ts = 124.184631
current_received_ts = 124.184067
current_seq = 641
count = 431
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 111us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.184631
last_received_ts = 124.184067
last_seq = 641
current_ts = 124.201294
current_received_ts = 124.200752
current_seq = 642
count = 432
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 81us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.201294
last_received_ts = 124.200752
last_seq = 642
current_ts = 124.217964
current_received_ts = 124.217422
current_seq = 643
count = 433
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 137us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.217964
last_received_ts = 124.217422
last_seq = 643
current_ts = 124.234627
current_received_ts = 124.234077
current_seq = 644
count = 434
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 81us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.234627
last_received_ts = 124.234077
last_seq = 644
current_ts = 124.251289
current_received_ts = 124.250763
current_seq = 645
count = 435
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.251289
last_received_ts = 124.250763
last_seq = 645
current_ts = 124.267952
current_received_ts = 124.267387
current_seq = 646
count = 436
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 114us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.267952
last_received_ts = 124.267387
last_seq = 646
current_ts = 124.284615
current_received_ts = 124.284073
current_seq = 647
count = 437
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.284615
last_received_ts = 124.284073
last_seq = 647
current_ts = 124.301285
current_received_ts = 124.300720
current_seq = 648
count = 438
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.301285
last_received_ts = 124.300720
last_seq = 648
current_ts = 124.317947
current_received_ts = 124.317390
current_seq = 649
count = 439
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 135us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.317947
last_received_ts = 124.317390
last_seq = 649
current_ts = 124.334610
current_received_ts = 124.334084
current_seq = 650
count = 440
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 72us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.334610
last_received_ts = 124.334084
last_seq = 650
current_ts = 124.351280
current_received_ts = 124.350739
current_seq = 651
count = 441
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 72us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.351280
last_received_ts = 124.350739
last_seq = 651
current_ts = 124.367943
current_received_ts = 124.367424
current_seq = 652
count = 442
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 125us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.367943
last_received_ts = 124.367424
last_seq = 652
current_ts = 124.384605
current_received_ts = 124.384071
current_seq = 653
count = 443
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 121us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.384605
last_received_ts = 124.384071
last_seq = 653
current_ts = 124.401268
current_received_ts = 124.400742
current_seq = 654
count = 444
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.401268
last_received_ts = 124.400742
last_seq = 654
current_ts = 124.417938
current_received_ts = 124.417419
current_seq = 655
count = 445
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 123us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.417938
last_received_ts = 124.417419
last_seq = 655
current_ts = 124.434593
current_received_ts = 124.434090
current_seq = 656
count = 446
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 85us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.434593
last_received_ts = 124.434090
last_seq = 656
current_ts = 124.451271
current_received_ts = 124.450722
current_seq = 657
count = 447
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.451271
last_received_ts = 124.450722
last_seq = 657
current_ts = 124.467926
current_received_ts = 124.467384
current_seq = 658
count = 448
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 140us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.467926
last_received_ts = 124.467384
last_seq = 658
current_ts = 124.484589
current_received_ts = 124.484070
current_seq = 659
count = 449
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 73us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.484589
last_received_ts = 124.484070
last_seq = 659
current_ts = 124.501251
current_received_ts = 124.500702
current_seq = 660
count = 450
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 70us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.501251
last_received_ts = 124.500702
last_seq = 660
current_ts = 124.517921
current_received_ts = 124.517418
current_seq = 661
count = 451
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 123us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.517921
last_received_ts = 124.517418
last_seq = 661
current_ts = 124.534584
current_received_ts = 124.534058
current_seq = 662
count = 452
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 74us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.534584
last_received_ts = 124.534058
last_seq = 662
current_ts = 124.551254
current_received_ts = 124.550713
current_seq = 663
count = 453
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.551254
last_received_ts = 124.550713
last_seq = 663
current_ts = 124.567917
current_received_ts = 124.567383
current_seq = 664
count = 454
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 154us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.567917
last_received_ts = 124.567383
last_seq = 664
current_ts = 124.584579
current_received_ts = 124.584045
current_seq = 665
count = 455
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 72us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.584579
last_received_ts = 124.584045
last_seq = 665
current_ts = 124.601242
current_received_ts = 124.600700
current_seq = 666
count = 456
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.601242
last_received_ts = 124.600700
last_seq = 666
current_ts = 124.617912
current_received_ts = 124.617378
current_seq = 667
count = 457
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 149us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.617912
last_received_ts = 124.617378
last_seq = 667
current_ts = 124.634583
current_received_ts = 124.634056
current_seq = 668
count = 458
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 69us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.634583
last_received_ts = 124.634056
last_seq = 668
current_ts = 124.651245
current_received_ts = 124.650681
current_seq = 669
count = 459
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 77us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.651245
last_received_ts = 124.650681
last_seq = 669
current_ts = 124.667908
current_received_ts = 124.667366
current_seq = 670
count = 460
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 148us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.667908
last_received_ts = 124.667366
last_seq = 670
current_ts = 124.684570
current_received_ts = 124.684059
current_seq = 671
count = 461
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.684570
last_received_ts = 124.684059
last_seq = 671
current_ts = 124.701233
current_received_ts = 124.700661
current_seq = 672
count = 462
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.701233
last_received_ts = 124.700661
last_seq = 672
current_ts = 124.717896
current_received_ts = 124.717377
current_seq = 673
count = 463
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 124us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.717896
last_received_ts = 124.717377
last_seq = 673
current_ts = 124.734558
current_received_ts = 124.733994
current_seq = 674
count = 464
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.734558
last_received_ts = 124.733994
last_seq = 674
current_ts = 124.751228
current_received_ts = 124.750671
current_seq = 675
count = 465
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.751228
last_received_ts = 124.750671
last_seq = 675
current_ts = 124.767899
current_received_ts = 124.767357
current_seq = 676
count = 466
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 140us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.767899
last_received_ts = 124.767357
last_seq = 676
current_ts = 124.784554
current_received_ts = 124.784027
current_seq = 677
count = 467
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 77us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.784554
last_received_ts = 124.784027
last_seq = 677
current_ts = 124.801224
current_received_ts = 124.800659
current_seq = 678
count = 468
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.801224
last_received_ts = 124.800659
last_seq = 678
current_ts = 124.817886
current_received_ts = 124.817345
current_seq = 679
count = 469
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 123us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.817886
last_received_ts = 124.817345
last_seq = 679
current_ts = 124.834557
current_received_ts = 124.834000
current_seq = 680
count = 470
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.834557
last_received_ts = 124.834000
last_seq = 680
current_ts = 124.851219
current_received_ts = 124.850670
current_seq = 681
count = 471
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.851219
last_received_ts = 124.850670
last_seq = 681
current_ts = 124.867882
current_received_ts = 124.867355
current_seq = 682
count = 472
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 142us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.867882
last_received_ts = 124.867355
last_seq = 682
current_ts = 124.884552
current_received_ts = 124.884041
current_seq = 683
count = 473
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 71us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.884552
last_received_ts = 124.884041
last_seq = 683
current_ts = 124.901207
current_received_ts = 124.900681
current_seq = 684
count = 474
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 72us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.901207
last_received_ts = 124.900681
last_seq = 684
current_ts = 124.917877
current_received_ts = 124.917320
current_seq = 685
count = 475
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 121us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.917877
last_received_ts = 124.917320
last_seq = 685
current_ts = 124.934540
current_received_ts = 124.934029
current_seq = 686
count = 476
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 70us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.934540
last_received_ts = 124.934029
last_seq = 686
current_ts = 124.951202
current_received_ts = 124.950661
current_seq = 687
count = 477
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 82us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.951202
last_received_ts = 124.950661
last_seq = 687
current_ts = 124.967873
current_received_ts = 124.967323
current_seq = 688
count = 478
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 134us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.967873
last_received_ts = 124.967323
last_seq = 688
current_ts = 124.984535
current_received_ts = 124.983963
current_seq = 689
count = 479
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 116us
(kms_flip:2365) DEBUG: name = flip
last_ts = 124.984535
last_received_ts = 124.983963
last_seq = 689
current_ts = 125.001198
current_received_ts = 125.000648
current_seq = 690
count = 480
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 76us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.001198
last_received_ts = 125.000648
last_seq = 690
current_ts = 125.017868
current_received_ts = 125.017319
current_seq = 691
count = 481
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 130us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.017868
last_received_ts = 125.017319
last_seq = 691
current_ts = 125.034531
current_received_ts = 125.033958
current_seq = 692
count = 482
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 106us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.034531
last_received_ts = 125.033958
last_seq = 692
current_ts = 125.051193
current_received_ts = 125.050636
current_seq = 693
count = 483
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 80us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.051193
last_received_ts = 125.050636
last_seq = 693
current_ts = 125.067863
current_received_ts = 125.067307
current_seq = 694
count = 484
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 76us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.067863
last_received_ts = 125.067307
last_seq = 694
current_ts = 125.084518
current_received_ts = 125.083977
current_seq = 695
count = 485
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 115us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.084518
last_received_ts = 125.083977
last_seq = 695
current_ts = 125.101189
current_received_ts = 125.100639
current_seq = 696
count = 486
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 78us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.101189
last_received_ts = 125.100639
last_seq = 696
current_ts = 125.117851
current_received_ts = 125.117279
current_seq = 697
count = 487
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 95us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.117851
last_received_ts = 125.117279
last_seq = 697
current_ts = 125.134514
current_received_ts = 125.133972
current_seq = 698
count = 488
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 110us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.134514
last_received_ts = 125.133972
last_seq = 698
current_ts = 125.151176
current_received_ts = 125.150650
current_seq = 699
count = 489
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 79us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.151176
last_received_ts = 125.150650
last_seq = 699
current_ts = 125.167847
current_received_ts = 125.167290
current_seq = 700
count = 490
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 88us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.167847
last_received_ts = 125.167290
last_seq = 700
current_ts = 125.184509
current_received_ts = 125.183968
current_seq = 701
count = 491
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 93us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.184509
last_received_ts = 125.183968
last_seq = 701
current_ts = 125.201172
current_received_ts = 125.200638
current_seq = 702
count = 492
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 110us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.201172
last_received_ts = 125.200638
last_seq = 702
current_ts = 125.217834
current_received_ts = 125.217361
current_seq = 703
count = 493
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 119us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.217834
last_received_ts = 125.217361
last_seq = 703
current_ts = 125.234505
current_received_ts = 125.233879
current_seq = 704
count = 494
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 141us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.234505
last_received_ts = 125.233879
last_seq = 704
current_ts = 125.251175
current_received_ts = 125.250481
current_seq = 705
count = 495
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 89us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.251175
last_received_ts = 125.250481
last_seq = 705
current_ts = 125.267838
current_received_ts = 125.267136
current_seq = 706
count = 496
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 74us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.267838
last_received_ts = 125.267136
last_seq = 706
current_ts = 125.284500
current_received_ts = 125.283806
current_seq = 707
count = 497
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 49us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.284500
last_received_ts = 125.283806
last_seq = 707
current_ts = 125.301163
current_received_ts = 125.300446
current_seq = 708
count = 498
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 67us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.301163
last_received_ts = 125.300446
last_seq = 708
current_ts = 125.317833
current_received_ts = 125.317139
current_seq = 709
count = 499
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 66us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.317833
last_received_ts = 125.317139
last_seq = 709
current_ts = 125.334496
current_received_ts = 125.333801
current_seq = 710
count = 500
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 67us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.334496
last_received_ts = 125.333801
last_seq = 710
current_ts = 125.351158
current_received_ts = 125.350456
current_seq = 711
count = 501
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 67us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.351158
last_received_ts = 125.350456
last_seq = 711
current_ts = 125.367821
current_received_ts = 125.367119
current_seq = 712
count = 502
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 66us
(kms_flip:2365) DEBUG: name = flip
last_ts = 125.367821
last_received_ts = 125.367119
last_seq = 712
current_ts = 125.384491
current_received_ts = 125.383972
current_seq = 713
count = 503
seq_step = 1
(kms_flip:2365) DEBUG: Vblank took 1041us
(kms_flip:2365) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2365) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2365) igt_core-INFO: Stack trace:
(kms_flip:2365) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2365) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2365) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2365) igt_core-INFO:   #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
(kms_flip:2365) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2365) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2365) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2365) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-eDP1: FAIL (9.848s)
Subtest flip-vs-expired-vblank: FAIL (32.298s)
(kms_flip:2365) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2352:
(kms_flip:2365) igt_kms-CRITICAL: Failed assertion: found_it
(kms_flip:2365) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
(kms_flip:2365) igt_kms-CRITICAL: DPMS property not found on 393
Dmesg
<6> [116.279335] [IGT] kms_flip: starting dynamic subtest C-eDP1
<7> [116.285382] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:431]
<7> [116.287908] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432]
<7> [116.292127] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [116.292592] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [116.292923] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [116.400771] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [116.401338] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [116.401839] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [116.402427] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [116.402714] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [116.403098] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [116.403435] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [116.403742] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [116.404059] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270: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> [116.404347] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [116.404616] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [116.404882] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [116.405318] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [116.405578] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [116.405817] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [116.406069] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [116.406302] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [116.406523] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [116.406744] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [116.406974] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [116.407189] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [116.407404] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [116.407615] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [116.407808] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [116.408010] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [116.408196] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [116.408378] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [116.408560] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [116.408744] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [116.408920] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [116.409105] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [116.409278] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [116.409435] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [116.409593] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [116.409754] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [116.409914] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [116.410086] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [116.410245] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [116.410401] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [116.410545] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [116.410685] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [116.410823] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [116.410968] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] fastset requirement not met, forcing full modeset
<7> [116.411108] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:270:pipe B] releasing DPLL 0
<7> [116.411327] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [116.411455] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:270:pipe B] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [116.411599] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:264:cursor B] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0
<7> [116.411707] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:270:pipe B] min cdclk: 173855 kHz -> 0 kHz
<7> [116.411853] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [116.411996] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [116.412129] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [116.412333] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:270:pipe B] enable: no [modeset]
<7> [116.412473] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:154:plane 1B] fb: [NOFB], visible: no
<7> [116.412600] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:184:plane 2B] fb: [NOFB], visible: no
<7> [116.412722] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:214:plane 3B] fb: [NOFB], visible: no
<7> [116.412842] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:244:plane 4B] fb: [NOFB], visible: no
<7> [116.412966] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:254:plane 5B] fb: [NOFB], visible: no
<7> [116.413091] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:264:cursor B] fb: [NOFB], visible: no
<7> [116.413453] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [116.413592] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [116.618999] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [116.619707] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe B
<7> [116.625348] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [116.625687] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [116.626037] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [116.678457] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [116.678783] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [116.685984] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [116.686296] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:270:pipe B]
<7> [116.686321] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [116.687750] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [116.688233] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [116.688712] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [116.689047] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [116.689339] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [116.689621] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [116.689902] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [116.690195] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [116.690471] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [116.690743] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [116.691032] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [116.691306] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [116.691581] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [116.691857] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [116.692157] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [116.692439] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [116.692790] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [116.693055] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [116.693291] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [116.693732] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_B
<7> [116.694105] 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> [116.694474] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [116.694859] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:270:pipe B]
<7> [116.695204] 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> [116.695604] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [116.695876] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [116.696739] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [116.697248] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [116.697342] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [116.697574] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [116.698027] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:389: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> [116.698371] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [116.698697] xe 0000:00:02.0: [drm:intel_psr_compute_config [xe]] PSR2 not supported in transcoder C
<7> [116.698996] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:389:pipe C] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [116.699332] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:389:pipe C]
<7> [116.699649] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.enable (expected no, found yes)
<7> [116.699954] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.active (expected no, found yes)
<7> [116.700242] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)
<7> [116.700504] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in lane_count (expected 0, found 4)
<7> [116.700769] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389: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> [116.701036] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [116.701286] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [116.701525] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [116.701765] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [116.701996] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [116.702213] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [116.702416] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [116.702618] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [116.702824] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [116.703036] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [116.703230] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [116.703412] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [116.703586] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [116.703757] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [116.703932] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [116.704098] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [116.704257] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [116.704417] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [116.704567] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [116.704724] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [116.704875] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [116.705039] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [116.705179] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [116.705312] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [116.705443] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [116.705574] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [116.705706] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [116.705838] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [116.705980] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [116.706107] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [116.706223] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [116.706336] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [116.706446] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [116.706560] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:389:pipe C] fastset requirement not met, forcing full modeset
<7> [116.706745] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no
<7> [116.706850] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:389:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4
<7> [116.706987] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:273:plane 1C] ddb ( 0 - 0) -> ( 0 - 2003), size 0 -> 2003
<7> [116.707083] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:383:cursor C] ddb ( 0 - 0) -> (2003 - 2048), size 0 -> 45
<7> [116.707157] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:273: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> [116.707228] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:273: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> [116.707299] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:273: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> [116.707368] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:273: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> [116.707464] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:389:pipe C] data rate 1390840 num active planes 1
<7> [116.707588] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [116.707705] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [116.707824] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [116.707965] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [116.708085] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [116.708234] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:389:pipe C] min cdclk: 0 kHz -> 173855 kHz
<7> [116.708380] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [116.708496] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [116.708606] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [116.708753] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:389:pipe C] allocated DPLL 0
<7> [116.708867] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:389:pipe C] reserving DPLL 0
<7> [116.708990] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:389:pipe C] enable: yes [modeset]
<7> [116.709119] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [116.709232] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: C, pipe bpp: 30, dithering: 0
<7> [116.709343] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [116.709452] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [116.709563] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [116.709679] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [116.709797] 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> [116.709914] 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> [116.710107] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [116.710235] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [116.710346] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: disabled, panel replay: disabled, selective fetch: disabled
<7> [116.710454] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [116.710562] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [116.710671] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 2, length 8
<7> [116.710780] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [116.710889] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [116.711013] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [116.711131] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [116.711250] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [116.711370] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [116.711483] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [116.711599] 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> [116.711709] 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> [116.711818] 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> [116.711933] 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> [116.712043] 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> [116.712152] 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> [116.712262] 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> [116.712373] 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> [116.712484] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0
<7> [116.712593] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [116.712702] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [116.712811] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [116.712919] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [116.713031] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [116.713139] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [116.713252] 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> [116.713364] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [116.713476] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [116.713588] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [116.713699] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [116.713809] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [116.713921] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [116.714043] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [116.714159] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [116.714271] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [116.714383] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [116.714493] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [116.714602] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [116.714713] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [116.714822] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [116.714944] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [116.714964] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [116.715059] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [116.715136] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [116.715167] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [116.715265] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [116.715275] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [116.715382] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [116.715422] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling always-on
<7> [116.715490] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [116.715597] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [116.715704] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:273:plane 1C] fb: [FB:431] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [116.715813] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [116.715920] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [116.716035] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:303:plane 2C] fb: [NOFB], visible: no
<7> [116.716142] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:333:plane 3C] fb: [NOFB], visible: no
<7> [116.716249] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:363:plane 4C] fb: [NOFB], visible: no
<7> [116.716356] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:373:plane 5C] fb: [NOFB], visible: no
<7> [116.716462] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:383:cursor C] fb: [NOFB], visible: no
<7> [116.716691] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [116.716788] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [116.716879] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [116.716980] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [116.717247] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling always-on
<7> [116.717360] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [116.717619] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [116.717780] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [116.717939] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_C
<7> [116.718104] 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> [116.718228] 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> [116.718363] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [116.718468] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [116.718586] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [116.718675] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [116.718760] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [116.718843] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [116.718955] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [116.719043] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [116.719125] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [116.719205] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [116.719285] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [116.719364] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [116.719443] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [116.719523] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [116.719602] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [116.719707] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xd
<7> [116.719895] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [116.720030] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [116.720936] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:389:pipe C]
<7> [116.721072] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [116.723692] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [116.723806] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (463 ms remaining)
<7> [117.195005] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [117.282968] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [117.283405] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on
<7> [117.283805] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [117.320153] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [117.320521] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [117.320876] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [117.321343] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [117.490995] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [117.491347] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [117.491619] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [117.493635] 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> [117.495158] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [117.495842] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [117.496862] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [117.498101] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [117.499066] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK
<7> [117.499325] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [117.500655] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [117.500948] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [117.501627] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe C
<7> [117.502076] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [117.502366] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe C
<7> [117.502727] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 13892
<7> [117.504189] xe 0000:00:02.0: [drm:intel_fbc_update [xe]] reserved 14745600 bytes of contiguous stolen space for FBC, limit: 2
<7> [117.504486] xe 0000:00:02.0: [drm:intel_fbc_update [xe]] Enabling FBC on [PLANE:273:plane 1C]
<7> [117.520346] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR1
<7> [117.521853] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [117.522286] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:389:pipe C]
<7> [120.066851] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off
<7> [120.067436] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<6> [126.128423] [IGT] kms_flip: finished subtest C-eDP1, FAIL
<6> [126.131569] [IGT] kms_flip: finished subtest flip-vs-expired-vblank, FAIL
<7> [126.151821] xe 0000:00:02.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:432] from all active usage due to RMFB ioctl
<7> [126.152601] xe 0000:00:02.0: [drm:atomic_remove_fb] Disabling [PLANE:273:plane 1C] because [FB:432] is removed
<7> [126.152733] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:273:plane 1C] ddb ( 0 - 2003) -> ( 0 - 0), size 2003 -> 0
<7> [126.153042] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:273: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> [126.153286] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:273: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> [126.153537] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:273: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> [126.153778] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:273: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> [126.154160] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:389:pipe C] data rate 0 num active planes 0
<7> [126.154549] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [126.154890] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [126.155266] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [126.155632] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [126.155930] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [126.157679] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR1
<7> [126.164594] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [126.164889] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f
<7> [126.179903] xe 0000:00:02.0: [drm:__intel_fbc_disable [xe]] Disabling FBC on [PLANE:273:plane 1C]
<7> [126.200394] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [126.200712] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000
<7> [126.200933] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [126.201154] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [126.201392] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]
<7> [126.201683] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [126.201906] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [126.202118] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [126.202330] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [126.202544] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)
<7> [126.202748] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [126.202938] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [126.203123] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [126.203300] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [126.203472] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [126.203704] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [126.203896] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [126.204069] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [126.204226] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [126.204375] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [126.204528] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [126.204669] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [126.204809] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [126.204943] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [126.205076] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [126.205205] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [126.205331] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [126.205473] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [126.205649] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [126.205772] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [126.205892] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [126.206008] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [126.206120] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [126.206246] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [126.206366] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [126.206474] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [126.206601] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [126.206710] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [126.206820] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [126.206928] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [126.207029] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [126.207130] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [126.207229] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [126.207326] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [126.207422] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.enable (expected yes, found no)
<7> [126.207530] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.active (expected yes, found no)
<7> [126.207626] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1)
<7> [126.207721] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in lane_count (expected 4, found 0)
<7> [126.207817] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389: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> [126.207922] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [126.208010] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [126.208096] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [126.208183] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [126.208267] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [126.208351] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [126.208433] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [126.208528] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [126.208624] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [126.208718] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [126.208816] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [126.208905] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [126.208992] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [126.209075] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [126.209149] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [126.209223] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [126.209297] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [126.209370] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [126.209444] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [126.209538] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [126.209635] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [126.209732] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [126.209821] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [126.209897] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [126.209971] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [126.210045] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [126.210119] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [126.210192] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [126.210265] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [126.210337] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [126.210409] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [126.210486] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [126.210577] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:389:pipe C] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [126.210670] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:389:pipe C] fastset requirement not met, forcing full modeset
<7> [126.210767] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:389:pipe C] releasing DPLL 0
<7> [126.210899] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xd -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [126.210970] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x4 -> 0x1
<7> [126.211040] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:389:pipe C] dbuf slices 0xc -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x4 -> 0x1
<7> [126.211112] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [126.211180] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [126.211241] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [126.211299] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0
<7> [126.211356] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87
<7> [126.211411] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88
<7> [126.211466] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:383:cursor C] ddb (2003 - 2048) -> ( 0 - 0), size 45 -> 0
<7> [126.211634] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1
<7> [126.211764] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [126.211856] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [126.211940] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [126.212025] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [126.212107] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [126.212189] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [126.212271] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:389:pipe C] min cdclk: 173855 kHz -> 0 kHz
<7> [126.212390] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0
<7> [126.212473] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0
<7> [126.212584] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [126.212695] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [126.212804] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [126.212889] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [126.212970] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [126.213050] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [126.213129] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [126.213208] 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> [126.213286] 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> [126.213364] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [126.213440] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [126.213527] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [126.213627] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [126.213727] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [126.213818] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [126.213894] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [126.213970] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [126.214045] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [126.214120] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [126.214194] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [126.214269] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [126.214344] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [126.214419] 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> [126.214498] 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> [126.214599] 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> [126.214701] 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> [126.214801] 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> [126.214879] 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> [126.214956] 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> [126.215032] 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> [126.215108] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0
<7> [126.215183] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [126.215258] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [126.215332] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [126.215407] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [126.215486] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [126.215574] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [126.215671] 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> [126.215769] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [126.215850] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [126.215923] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [126.215996] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [126.216069] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [126.216141] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [126.216213] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [126.216285] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [126.216364] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [126.216446] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [126.216551] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [126.216659] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [126.216757] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [126.216842] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [126.216917] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [126.216991] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [126.217064] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [126.217137] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [126.217211] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [126.217285] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [126.217359] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [126.217432] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:394] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [126.217520] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [126.217616] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [126.217713] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [126.217804] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [126.217876] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [126.217949] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [126.218021] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [126.218092] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:389:pipe C] enable: no [modeset]
<7> [126.218163] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:273:plane 1C] fb: [NOFB], visible: no
<7> [126.218235] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:303:plane 2C] fb: [NOFB], visible: no
<7> [126.218307] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:333:plane 3C] fb: [NOFB], visible: no
<7> [126.218378] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:363:plane 4C] fb: [NOFB], visible: no
<7> [126.218451] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:373:plane 5C] fb: [NOFB], visible: no
<7> [126.218545] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:383:cursor C] fb: [NOFB], visible: no
<7> [126.218734] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [126.218908] 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> [126.219095] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [126.219179] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [126.426707] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [126.427346] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe C
<7> [126.430871] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [126.431279] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [126.431728] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [126.484025] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [126.484686] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [126.490414] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [126.490976] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x4, on? 1) for [CRTC:389:pipe C]
<7> [126.491028] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [126.492548] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [126.493068] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [126.493639] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [126.493989] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [126.494321] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [126.494693] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [126.495043] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [126.495349] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [126.495746] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [126.496106] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [126.496464] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [126.496854] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [126.497148] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [126.497436] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [126.497786] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [126.498212] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [126.498762] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [126.499057] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [126.499395] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [126.500646] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]
<7> [126.501119] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [126.503577] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [126.503956] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (487 ms remaining)
<7> [126.522298] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [126.522773] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [126.523195] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [126.523633] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [126.994805] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [127.056300] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [127.056735] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on
<7> [127.057062] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [127.093483] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [127.093940] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [127.094358] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [127.094782] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [127.263327] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [127.263831] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [127.264192] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [127.266396] 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> [127.268087] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [127.269070] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [127.270501] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [127.272055] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [127.273354] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK
<7> [127.273853] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [127.275410] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [127.275881] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [127.276762] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [127.277306] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [127.277801] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [127.278278] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 13892
<7> [127.294186] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [127.296055] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [127.296486] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [127.299480] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_C
<7> [127.299878] 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> [127.300299] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [127.300788] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:389:pipe C]
<7> [127.301243] xe 0000:00:02.0: [drm:drm_client_dev_restore] fbdev: ret=0
<6> [127.302531] [IGT] kms_flip: exiting, ret=98
Created at 2026-04-21 15:28:28