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

Result: Fail

i915_display_info20 igt_runner20 results20.json results20-xe-load.json guc_logs20.tar i915_display_info_post_exec20 serial_data20 boot20 dmesg20

DetailValue
Duration 10.75 seconds
Hostname 
shard-lnl-2
Igt-Version 
IGT-Version: 2.4-g22222b7d9 (x86_64) (Linux: 7.1.0-rc3-lgci-xe-xe-pw-160223v3-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:2074 __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 ../sysdeps/nptl/libc_start_call_main.h:74 __libc_start_call_main()
  #6 ../csu/libc-start.c:128 __libc_start_main@@GLIBC_2.34()
  #7 [_start+0x25]
Dynamic subtest C-eDP1: FAIL (10.749s)
Subtest flip-vs-expired-vblank: FAIL (25.575s)
Stack trace:
  #0 ../lib/igt_core.c:2074 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2352 kmstest_set_connector_dpms()
  #2 ../lib/igt_core.c:2960 igt_atexit_handler()
  #3 ./stdlib/exit.c:109 __run_exit_handlers()
  #4 [exit+0x1e]
  #5 ../lib/igt_core.c:2415 igt_exit()
  #6 [main+0x3f]
  #7 ../sysdeps/nptl/libc_start_call_main.h:74 __libc_start_call_main()
  #8 ../csu/libc-start.c:128 __libc_start_main@@GLIBC_2.34()
  #9 [_start+0x25]
Err 
Starting dynamic subtest: C-eDP1
[397.906452] (kms_flip:9940) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[397.907654] (kms_flip:9940) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest C-eDP1 failed.
**** DEBUG ****
[395.872593] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.856934
last_received_ts = 397.856293
last_seq = 770
current_ts = 397.873627
current_received_ts = 397.873077
current_seq = 771
count = 436
seq_step = 1
[395.872707] (kms_flip:9940) DEBUG: Vblank took 100us
[395.889160] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.873627
last_received_ts = 397.873077
last_seq = 771
current_ts = 397.890289
current_received_ts = 397.889648
current_seq = 772
count = 437
seq_step = 1
[395.889283] (kms_flip:9940) DEBUG: Vblank took 110us
[395.905775] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.890289
last_received_ts = 397.889648
last_seq = 772
current_ts = 397.906952
current_received_ts = 397.906281
current_seq = 773
count = 438
seq_step = 1
[395.905907] (kms_flip:9940) DEBUG: Vblank took 127us
[395.922585] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.906952
last_received_ts = 397.906281
last_seq = 773
current_ts = 397.923615
current_received_ts = 397.923096
current_seq = 774
count = 439
seq_step = 1
[395.922676] (kms_flip:9940) DEBUG: Vblank took 79us
[395.939139] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.923615
last_received_ts = 397.923096
last_seq = 774
current_ts = 397.940277
current_received_ts = 397.939636
current_seq = 775
count = 440
seq_step = 1
[395.939253] (kms_flip:9940) DEBUG: Vblank took 101us
[395.955747] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.940277
last_received_ts = 397.939636
last_seq = 775
current_ts = 397.956940
current_received_ts = 397.956238
current_seq = 776
count = 441
seq_step = 1
[395.955870] (kms_flip:9940) DEBUG: Vblank took 117us
[395.972558] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.956940
last_received_ts = 397.956238
last_seq = 776
current_ts = 397.973602
current_received_ts = 397.973053
current_seq = 777
count = 442
seq_step = 1
[395.972654] (kms_flip:9940) DEBUG: Vblank took 83us
[395.989131] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.973602
last_received_ts = 397.973053
last_seq = 777
current_ts = 397.990265
current_received_ts = 397.989624
current_seq = 778
count = 443
seq_step = 1
[395.989245] (kms_flip:9940) DEBUG: Vblank took 100us
[396.005770] (kms_flip:9940) DEBUG: name = flip
last_ts = 397.990265
last_received_ts = 397.989624
last_seq = 778
current_ts = 398.006927
current_received_ts = 398.006287
current_seq = 779
count = 444
seq_step = 1
[396.005906] (kms_flip:9940) DEBUG: Vblank took 129us
[396.022584] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.006927
last_received_ts = 398.006287
last_seq = 779
current_ts = 398.023590
current_received_ts = 398.023071
current_seq = 780
count = 445
seq_step = 1
[396.022681] (kms_flip:9940) DEBUG: Vblank took 82us
[396.039130] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.023590
last_received_ts = 398.023071
last_seq = 780
current_ts = 398.040253
current_received_ts = 398.039612
current_seq = 781
count = 446
seq_step = 1
[396.039275] (kms_flip:9940) DEBUG: Vblank took 131us
[396.055769] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.040253
last_received_ts = 398.039612
last_seq = 781
current_ts = 398.056915
current_received_ts = 398.056274
current_seq = 782
count = 447
seq_step = 1
[396.055887] (kms_flip:9940) DEBUG: Vblank took 112us
[396.072593] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.056915
last_received_ts = 398.056274
last_seq = 782
current_ts = 398.073578
current_received_ts = 398.073090
current_seq = 783
count = 448
seq_step = 1
[396.072702] (kms_flip:9940) DEBUG: Vblank took 96us
[396.089128] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.073578
last_received_ts = 398.073090
last_seq = 783
current_ts = 398.090240
current_received_ts = 398.089630
current_seq = 784
count = 449
seq_step = 1
[396.089255] (kms_flip:9940) DEBUG: Vblank took 115us
[396.105743] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.090240
last_received_ts = 398.089630
last_seq = 784
current_ts = 398.106903
current_received_ts = 398.106232
current_seq = 785
count = 450
seq_step = 1
[396.105816] (kms_flip:9940) DEBUG: Vblank took 67us
[396.122562] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.106903
last_received_ts = 398.106232
last_seq = 785
current_ts = 398.123566
current_received_ts = 398.123047
current_seq = 786
count = 451
seq_step = 1
[396.122672] (kms_flip:9940) DEBUG: Vblank took 95us
[396.139131] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.123566
last_received_ts = 398.123047
last_seq = 786
current_ts = 398.140228
current_received_ts = 398.139618
current_seq = 787
count = 452
seq_step = 1
[396.139253] (kms_flip:9940) DEBUG: Vblank took 108us
[396.155750] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.140228
last_received_ts = 398.139618
last_seq = 787
current_ts = 398.156891
current_received_ts = 398.156250
current_seq = 788
count = 453
seq_step = 1
[396.155869] (kms_flip:9940) DEBUG: Vblank took 114us
[396.172628] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.156891
last_received_ts = 398.156250
last_seq = 788
current_ts = 398.173553
current_received_ts = 398.173096
current_seq = 789
count = 454
seq_step = 1
[396.172782] (kms_flip:9940) DEBUG: Vblank took 118us
[396.189113] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.173553
last_received_ts = 398.173096
last_seq = 789
current_ts = 398.190216
current_received_ts = 398.189575
current_seq = 790
count = 455
seq_step = 1
[396.189201] (kms_flip:9940) DEBUG: Vblank took 73us
[396.205729] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.190216
last_received_ts = 398.189575
last_seq = 790
current_ts = 398.206879
current_received_ts = 398.206207
current_seq = 791
count = 456
seq_step = 1
[396.205823] (kms_flip:9940) DEBUG: Vblank took 81us
[396.222383] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.206879
last_received_ts = 398.206207
last_seq = 791
current_ts = 398.223541
current_received_ts = 398.222870
current_seq = 792
count = 457
seq_step = 1
[396.222490] (kms_flip:9940) DEBUG: Vblank took 95us
[396.239131] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.223541
last_received_ts = 398.222870
last_seq = 792
current_ts = 398.240204
current_received_ts = 398.239624
current_seq = 793
count = 458
seq_step = 1
[396.239199] (kms_flip:9940) DEBUG: Vblank took 58us
[396.255712] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.240204
last_received_ts = 398.239624
last_seq = 793
current_ts = 398.256866
current_received_ts = 398.256195
current_seq = 794
count = 459
seq_step = 1
[396.255794] (kms_flip:9940) DEBUG: Vblank took 74us
[396.272431] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.256866
last_received_ts = 398.256195
last_seq = 794
current_ts = 398.273529
current_received_ts = 398.272919
current_seq = 795
count = 460
seq_step = 1
[396.272545] (kms_flip:9940) DEBUG: Vblank took 107us
[396.289083] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.273529
last_received_ts = 398.272919
last_seq = 795
current_ts = 398.290192
current_received_ts = 398.289581
current_seq = 796
count = 461
seq_step = 1
[396.289159] (kms_flip:9940) DEBUG: Vblank took 69us
[396.305736] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.290192
last_received_ts = 398.289581
last_seq = 796
current_ts = 398.306854
current_received_ts = 398.306213
current_seq = 797
count = 462
seq_step = 1
[396.305812] (kms_flip:9940) DEBUG: Vblank took 69us
[396.322529] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.306854
last_received_ts = 398.306213
last_seq = 797
current_ts = 398.323517
current_received_ts = 398.322998
current_seq = 798
count = 463
seq_step = 1
[396.322579] (kms_flip:9940) DEBUG: Vblank took 44us
[396.339074] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.323517
last_received_ts = 398.322998
last_seq = 798
current_ts = 398.340179
current_received_ts = 398.339569
current_seq = 799
count = 464
seq_step = 1
[396.339146] (kms_flip:9940) DEBUG: Vblank took 67us
[396.355827] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.340179
last_received_ts = 398.339569
last_seq = 799
current_ts = 398.356842
current_received_ts = 398.356323
current_seq = 800
count = 465
seq_step = 1
[396.355904] (kms_flip:9940) DEBUG: Vblank took 72us
[396.372412] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.356842
last_received_ts = 398.356323
last_seq = 800
current_ts = 398.373505
current_received_ts = 398.372894
current_seq = 801
count = 466
seq_step = 1
[396.372490] (kms_flip:9940) DEBUG: Vblank took 72us
[396.389105] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.373505
last_received_ts = 398.372894
last_seq = 801
current_ts = 398.390167
current_received_ts = 398.389587
current_seq = 802
count = 467
seq_step = 1
[396.389183] (kms_flip:9940) DEBUG: Vblank took 73us
[396.405761] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.390167
last_received_ts = 398.389587
last_seq = 802
current_ts = 398.406830
current_received_ts = 398.406250
current_seq = 803
count = 468
seq_step = 1
[396.405841] (kms_flip:9940) DEBUG: Vblank took 75us
[396.422484] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.406830
last_received_ts = 398.406250
last_seq = 803
current_ts = 398.423523
current_received_ts = 398.422974
current_seq = 804
count = 469
seq_step = 1
[396.422589] (kms_flip:9940) DEBUG: Vblank took 99us
[396.439132] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.423523
last_received_ts = 398.422974
last_seq = 804
current_ts = 398.440155
current_received_ts = 398.439575
current_seq = 805
count = 470
seq_step = 1
[396.439335] (kms_flip:9940) DEBUG: Vblank took 172us
[396.455590] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.440155
last_received_ts = 398.439575
last_seq = 805
current_ts = 398.456848
current_received_ts = 398.456085
current_seq = 806
count = 471
seq_step = 1
[396.455679] (kms_flip:9940) DEBUG: Vblank took 82us
[396.472396] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.456848
last_received_ts = 398.456085
last_seq = 806
current_ts = 398.473511
current_received_ts = 398.472870
current_seq = 807
count = 472
seq_step = 1
[396.472548] (kms_flip:9940) DEBUG: Vblank took 138us
[396.489036] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.473511
last_received_ts = 398.472870
last_seq = 807
current_ts = 398.490173
current_received_ts = 398.489502
current_seq = 808
count = 473
seq_step = 1
[396.489153] (kms_flip:9940) DEBUG: Vblank took 105us
[396.505557] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.490173
last_received_ts = 398.489502
last_seq = 808
current_ts = 398.506836
current_received_ts = 398.506042
current_seq = 809
count = 474
seq_step = 1
[396.505611] (kms_flip:9940) DEBUG: Vblank took 48us
[396.522482] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.506836
last_received_ts = 398.506042
last_seq = 809
current_ts = 398.523499
current_received_ts = 398.522949
current_seq = 810
count = 475
seq_step = 1
[396.522616] (kms_flip:9940) DEBUG: Vblank took 120us
[396.539052] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.523499
last_received_ts = 398.522949
last_seq = 810
current_ts = 398.540161
current_received_ts = 398.539520
current_seq = 811
count = 476
seq_step = 1
[396.539212] (kms_flip:9940) DEBUG: Vblank took 145us
[396.555649] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.540161
last_received_ts = 398.539520
last_seq = 811
current_ts = 398.556824
current_received_ts = 398.556122
current_seq = 812
count = 477
seq_step = 1
[396.555771] (kms_flip:9940) DEBUG: Vblank took 116us
[396.572470] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.556824
last_received_ts = 398.556122
last_seq = 812
current_ts = 398.573486
current_received_ts = 398.572937
current_seq = 813
count = 478
seq_step = 1
[396.572602] (kms_flip:9940) DEBUG: Vblank took 119us
[396.589036] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.573486
last_received_ts = 398.572937
last_seq = 813
current_ts = 398.590149
current_received_ts = 398.589508
current_seq = 814
count = 479
seq_step = 1
[396.589151] (kms_flip:9940) DEBUG: Vblank took 102us
[396.605681] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.590149
last_received_ts = 398.589508
last_seq = 814
current_ts = 398.606812
current_received_ts = 398.606171
current_seq = 815
count = 480
seq_step = 1
[396.605823] (kms_flip:9940) DEBUG: Vblank took 136us
[396.622431] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.606812
last_received_ts = 398.606171
last_seq = 815
current_ts = 398.623474
current_received_ts = 398.622894
current_seq = 816
count = 481
seq_step = 1
[396.622561] (kms_flip:9940) DEBUG: Vblank took 117us
[396.639048] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.623474
last_received_ts = 398.622894
last_seq = 816
current_ts = 398.640137
current_received_ts = 398.639526
current_seq = 817
count = 482
seq_step = 1
[396.639172] (kms_flip:9940) DEBUG: Vblank took 109us
[396.655671] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.640137
last_received_ts = 398.639526
last_seq = 817
current_ts = 398.656799
current_received_ts = 398.656158
current_seq = 818
count = 483
seq_step = 1
[396.655809] (kms_flip:9940) DEBUG: Vblank took 131us
[396.672437] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.656799
last_received_ts = 398.656158
last_seq = 818
current_ts = 398.673462
current_received_ts = 398.672913
current_seq = 819
count = 484
seq_step = 1
[396.672562] (kms_flip:9940) DEBUG: Vblank took 112us
[396.689040] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.673462
last_received_ts = 398.672913
last_seq = 819
current_ts = 398.690125
current_received_ts = 398.689514
current_seq = 820
count = 485
seq_step = 1
[396.689193] (kms_flip:9940) DEBUG: Vblank took 137us
[396.705650] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.690125
last_received_ts = 398.689514
last_seq = 820
current_ts = 398.706787
current_received_ts = 398.706116
current_seq = 821
count = 486
seq_step = 1
[396.705772] (kms_flip:9940) DEBUG: Vblank took 115us
[396.722455] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.706787
last_received_ts = 398.706116
last_seq = 821
current_ts = 398.723450
current_received_ts = 398.722931
current_seq = 822
count = 487
seq_step = 1
[396.722598] (kms_flip:9940) DEBUG: Vblank took 130us
[396.739007] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.723450
last_received_ts = 398.722931
last_seq = 822
current_ts = 398.740112
current_received_ts = 398.739471
current_seq = 823
count = 488
seq_step = 1
[396.739117] (kms_flip:9940) DEBUG: Vblank took 98us
[396.755681] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.740112
last_received_ts = 398.739471
last_seq = 823
current_ts = 398.756775
current_received_ts = 398.756165
current_seq = 824
count = 489
seq_step = 1
[396.755806] (kms_flip:9940) DEBUG: Vblank took 112us
[396.772292] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.756775
last_received_ts = 398.756165
last_seq = 824
current_ts = 398.773438
current_received_ts = 398.772766
current_seq = 825
count = 490
seq_step = 1
[396.772424] (kms_flip:9940) DEBUG: Vblank took 120us
[396.789069] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.773438
last_received_ts = 398.772766
last_seq = 825
current_ts = 398.790100
current_received_ts = 398.789551
current_seq = 826
count = 491
seq_step = 1
[396.789158] (kms_flip:9940) DEBUG: Vblank took 76us
[396.805672] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.790100
last_received_ts = 398.789551
last_seq = 826
current_ts = 398.806763
current_received_ts = 398.806152
current_seq = 827
count = 492
seq_step = 1
[396.805803] (kms_flip:9940) DEBUG: Vblank took 119us
[396.822358] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.806763
last_received_ts = 398.806152
last_seq = 827
current_ts = 398.823425
current_received_ts = 398.822815
current_seq = 828
count = 493
seq_step = 1
[396.822459] (kms_flip:9940) DEBUG: Vblank took 88us
[396.838981] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.823425
last_received_ts = 398.822815
last_seq = 828
current_ts = 398.840088
current_received_ts = 398.839447
current_seq = 829
count = 494
seq_step = 1
[396.839105] (kms_flip:9940) DEBUG: Vblank took 112us
[396.855630] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.840088
last_received_ts = 398.839447
last_seq = 829
current_ts = 398.856750
current_received_ts = 398.856110
current_seq = 830
count = 495
seq_step = 1
[396.855777] (kms_flip:9940) DEBUG: Vblank took 139us
[396.872407] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.856750
last_received_ts = 398.856110
last_seq = 830
current_ts = 398.873413
current_received_ts = 398.872864
current_seq = 831
count = 496
seq_step = 1
[396.872509] (kms_flip:9940) DEBUG: Vblank took 89us
[396.888993] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.873413
last_received_ts = 398.872864
last_seq = 831
current_ts = 398.890076
current_received_ts = 398.889465
current_seq = 832
count = 497
seq_step = 1
[396.889122] (kms_flip:9940) DEBUG: Vblank took 116us
[396.905613] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.890076
last_received_ts = 398.889465
last_seq = 832
current_ts = 398.906738
current_received_ts = 398.906097
current_seq = 833
count = 498
seq_step = 1
[396.905691] (kms_flip:9940) DEBUG: Vblank took 71us
[396.922416] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.906738
last_received_ts = 398.906097
last_seq = 833
current_ts = 398.923401
current_received_ts = 398.922882
current_seq = 834
count = 499
seq_step = 1
[396.922515] (kms_flip:9940) DEBUG: Vblank took 86us
[396.938883] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.923401
last_received_ts = 398.922882
last_seq = 834
current_ts = 398.940063
current_received_ts = 398.939331
current_seq = 835
count = 500
seq_step = 1
[396.939013] (kms_flip:9940) DEBUG: Vblank took 117us
[396.955725] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.940063
last_received_ts = 398.939331
last_seq = 835
current_ts = 398.956726
current_received_ts = 398.956177
current_seq = 836
count = 501
seq_step = 1
[396.955812] (kms_flip:9940) DEBUG: Vblank took 75us
[396.972391] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.956726
last_received_ts = 398.956177
last_seq = 836
current_ts = 398.973419
current_received_ts = 398.972870
current_seq = 837
count = 502
seq_step = 1
[396.972488] (kms_flip:9940) DEBUG: Vblank took 84us
[396.988973] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.973419
last_received_ts = 398.972870
last_seq = 837
current_ts = 398.990051
current_received_ts = 398.989441
current_seq = 838
count = 503
seq_step = 1
[396.989102] (kms_flip:9940) DEBUG: Vblank took 116us
[397.005584] (kms_flip:9940) DEBUG: name = flip
last_ts = 398.990051
last_received_ts = 398.989441
last_seq = 838
current_ts = 399.006744
current_received_ts = 399.006073
current_seq = 839
count = 504
seq_step = 1
[397.005657] (kms_flip:9940) DEBUG: Vblank took 67us
[397.022346] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.006744
last_received_ts = 399.006073
last_seq = 839
current_ts = 399.023407
current_received_ts = 399.022797
current_seq = 840
count = 505
seq_step = 1
[397.022445] (kms_flip:9940) DEBUG: Vblank took 85us
[397.038957] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.023407
last_received_ts = 399.022797
last_seq = 840
current_ts = 399.040070
current_received_ts = 399.039429
current_seq = 841
count = 506
seq_step = 1
[397.039084] (kms_flip:9940) DEBUG: Vblank took 115us
[397.055748] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.040070
last_received_ts = 399.039429
last_seq = 841
current_ts = 399.056732
current_received_ts = 399.056213
current_seq = 842
count = 507
seq_step = 1
[397.055860] (kms_flip:9940) DEBUG: Vblank took 98us
[397.072273] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.056732
last_received_ts = 399.056213
last_seq = 842
current_ts = 399.073395
current_received_ts = 399.072723
current_seq = 843
count = 508
seq_step = 1
[397.072383] (kms_flip:9940) DEBUG: Vblank took 96us
[397.088962] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.073395
last_received_ts = 399.072723
last_seq = 843
current_ts = 399.090057
current_received_ts = 399.089417
current_seq = 844
count = 509
seq_step = 1
[397.089131] (kms_flip:9940) DEBUG: Vblank took 156us
[397.105601] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.090057
last_received_ts = 399.089417
last_seq = 844
current_ts = 399.106720
current_received_ts = 399.106079
current_seq = 845
count = 510
seq_step = 1
[397.105677] (kms_flip:9940) DEBUG: Vblank took 70us
[397.122393] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.106720
last_received_ts = 399.106079
last_seq = 845
current_ts = 399.123383
current_received_ts = 399.122864
current_seq = 846
count = 511
seq_step = 1
[397.122490] (kms_flip:9940) DEBUG: Vblank took 83us
[397.138948] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.123383
last_received_ts = 399.122864
last_seq = 846
current_ts = 399.140045
current_received_ts = 399.139404
current_seq = 847
count = 512
seq_step = 1
[397.139080] (kms_flip:9940) DEBUG: Vblank took 118us
[397.155723] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.140045
last_received_ts = 399.139404
last_seq = 847
current_ts = 399.156708
current_received_ts = 399.156189
current_seq = 848
count = 513
seq_step = 1
[397.155830] (kms_flip:9940) DEBUG: Vblank took 93us
[397.172331] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.156708
last_received_ts = 399.156189
last_seq = 848
current_ts = 399.173370
current_received_ts = 399.172791
current_seq = 849
count = 514
seq_step = 1
[397.172430] (kms_flip:9940) DEBUG: Vblank took 87us
[397.188923] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.173370
last_received_ts = 399.172791
last_seq = 849
current_ts = 399.190033
current_received_ts = 399.189392
current_seq = 850
count = 515
seq_step = 1
[397.189030] (kms_flip:9940) DEBUG: Vblank took 95us
[397.205704] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.190033
last_received_ts = 399.189392
last_seq = 850
current_ts = 399.206696
current_received_ts = 399.206146
current_seq = 851
count = 516
seq_step = 1
[397.205791] (kms_flip:9940) DEBUG: Vblank took 76us
[397.222348] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.206696
last_received_ts = 399.206146
last_seq = 851
current_ts = 399.223358
current_received_ts = 399.222809
current_seq = 852
count = 517
seq_step = 1
[397.222471] (kms_flip:9940) DEBUG: Vblank took 108us
[397.238937] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.223358
last_received_ts = 399.222809
last_seq = 852
current_ts = 399.240021
current_received_ts = 399.239380
current_seq = 853
count = 518
seq_step = 1
[397.239059] (kms_flip:9940) DEBUG: Vblank took 109us
[397.255691] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.240021
last_received_ts = 399.239380
last_seq = 853
current_ts = 399.256683
current_received_ts = 399.256134
current_seq = 854
count = 519
seq_step = 1
[397.255806] (kms_flip:9940) DEBUG: Vblank took 100us
[397.272365] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.256683
last_received_ts = 399.256134
last_seq = 854
current_ts = 399.273346
current_received_ts = 399.272827
current_seq = 855
count = 520
seq_step = 1
[397.272478] (kms_flip:9940) DEBUG: Vblank took 99us
[397.288948] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.273346
last_received_ts = 399.272827
last_seq = 855
current_ts = 399.290009
current_received_ts = 399.289398
current_seq = 856
count = 521
seq_step = 1
[397.289070] (kms_flip:9940) DEBUG: Vblank took 110us
[397.305558] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.290009
last_received_ts = 399.289398
last_seq = 856
current_ts = 399.306671
current_received_ts = 399.306030
current_seq = 857
count = 522
seq_step = 1
[397.305690] (kms_flip:9940) DEBUG: Vblank took 126us
[397.322155] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.306671
last_received_ts = 399.306030
last_seq = 857
current_ts = 399.323334
current_received_ts = 399.322632
current_seq = 858
count = 523
seq_step = 1
[397.322216] (kms_flip:9940) DEBUG: Vblank took 57us
[397.338847] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.323334
last_received_ts = 399.322632
last_seq = 858
current_ts = 399.339996
current_received_ts = 399.339325
current_seq = 859
count = 524
seq_step = 1
[397.338905] (kms_flip:9940) DEBUG: Vblank took 54us
[397.355612] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.339996
last_received_ts = 399.339325
last_seq = 859
current_ts = 399.356659
current_received_ts = 399.356079
current_seq = 860
count = 525
seq_step = 1
[397.355712] (kms_flip:9940) DEBUG: Vblank took 88us
[397.372238] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.356659
last_received_ts = 399.356079
last_seq = 860
current_ts = 399.373322
current_received_ts = 399.372681
current_seq = 861
count = 526
seq_step = 1
[397.372353] (kms_flip:9940) DEBUG: Vblank took 102us
[397.388884] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.373322
last_received_ts = 399.372681
last_seq = 861
current_ts = 399.389984
current_received_ts = 399.389343
current_seq = 862
count = 527
seq_step = 1
[397.389020] (kms_flip:9940) DEBUG: Vblank took 130us
[397.405632] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.389984
last_received_ts = 399.389343
last_seq = 862
current_ts = 399.406647
current_received_ts = 399.406097
current_seq = 863
count = 528
seq_step = 1
[397.405733] (kms_flip:9940) DEBUG: Vblank took 89us
[397.422261] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.406647
last_received_ts = 399.406097
last_seq = 863
current_ts = 399.423309
current_received_ts = 399.422699
current_seq = 864
count = 529
seq_step = 1
[397.422386] (kms_flip:9940) DEBUG: Vblank took 110us
[397.438837] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.423309
last_received_ts = 399.422699
last_seq = 864
current_ts = 399.439972
current_received_ts = 399.439301
current_seq = 865
count = 530
seq_step = 1
[397.438974] (kms_flip:9940) DEBUG: Vblank took 131us
[397.455664] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.439972
last_received_ts = 399.439301
last_seq = 865
current_ts = 399.456635
current_received_ts = 399.456116
current_seq = 866
count = 531
seq_step = 1
[397.455765] (kms_flip:9940) DEBUG: Vblank took 88us
[397.472253] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.456635
last_received_ts = 399.456116
last_seq = 866
current_ts = 399.473297
current_received_ts = 399.472687
current_seq = 867
count = 532
seq_step = 1
[397.472374] (kms_flip:9940) DEBUG: Vblank took 105us
[397.488869] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.473297
last_received_ts = 399.472687
last_seq = 867
current_ts = 399.489990
current_received_ts = 399.489319
current_seq = 868
count = 533
seq_step = 1
[397.488992] (kms_flip:9940) DEBUG: Vblank took 117us
[397.505640] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.489990
last_received_ts = 399.489319
last_seq = 868
current_ts = 399.506653
current_received_ts = 399.506104
current_seq = 869
count = 534
seq_step = 1
[397.505741] (kms_flip:9940) DEBUG: Vblank took 88us
[397.522228] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.506653
last_received_ts = 399.506104
last_seq = 869
current_ts = 399.523315
current_received_ts = 399.522675
current_seq = 870
count = 535
seq_step = 1
[397.522385] (kms_flip:9940) DEBUG: Vblank took 142us
[397.538855] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.523315
last_received_ts = 399.522675
last_seq = 870
current_ts = 399.539978
current_received_ts = 399.539307
current_seq = 871
count = 536
seq_step = 1
[397.538987] (kms_flip:9940) DEBUG: Vblank took 126us
[397.555634] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.539978
last_received_ts = 399.539307
last_seq = 871
current_ts = 399.556641
current_received_ts = 399.556091
current_seq = 872
count = 537
seq_step = 1
[397.555743] (kms_flip:9940) DEBUG: Vblank took 96us
[397.572297] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.556641
last_received_ts = 399.556091
last_seq = 872
current_ts = 399.573303
current_received_ts = 399.572754
current_seq = 873
count = 538
seq_step = 1
[397.572393] (kms_flip:9940) DEBUG: Vblank took 84us
[397.588908] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.573303
last_received_ts = 399.572754
last_seq = 873
current_ts = 399.589966
current_received_ts = 399.589355
current_seq = 874
count = 539
seq_step = 1
[397.589035] (kms_flip:9940) DEBUG: Vblank took 109us
[397.605511] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.589966
last_received_ts = 399.589355
last_seq = 874
current_ts = 399.606628
current_received_ts = 399.605957
current_seq = 875
count = 540
seq_step = 1
[397.605603] (kms_flip:9940) DEBUG: Vblank took 86us
[397.622167] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.606628
last_received_ts = 399.605957
last_seq = 875
current_ts = 399.623291
current_received_ts = 399.622620
current_seq = 876
count = 541
seq_step = 1
[397.622234] (kms_flip:9940) DEBUG: Vblank took 62us
[397.638880] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.623291
last_received_ts = 399.622620
last_seq = 876
current_ts = 399.639954
current_received_ts = 399.639313
current_seq = 877
count = 542
seq_step = 1
[397.638994] (kms_flip:9940) DEBUG: Vblank took 100us
[397.655627] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.639954
last_received_ts = 399.639313
last_seq = 877
current_ts = 399.656616
current_received_ts = 399.656067
current_seq = 878
count = 543
seq_step = 1
[397.655728] (kms_flip:9940) DEBUG: Vblank took 89us
[397.672194] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.656616
last_received_ts = 399.656067
last_seq = 878
current_ts = 399.673279
current_received_ts = 399.672638
current_seq = 879
count = 544
seq_step = 1
[397.672315] (kms_flip:9940) DEBUG: Vblank took 107us
[397.688861] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.673279
last_received_ts = 399.672638
last_seq = 879
current_ts = 399.689941
current_received_ts = 399.689301
current_seq = 880
count = 545
seq_step = 1
[397.688972] (kms_flip:9940) DEBUG: Vblank took 98us
[397.705625] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.689941
last_received_ts = 399.689301
last_seq = 880
current_ts = 399.706604
current_received_ts = 399.706085
current_seq = 881
count = 546
seq_step = 1
[397.705721] (kms_flip:9940) DEBUG: Vblank took 83us
[397.722197] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.706604
last_received_ts = 399.706085
last_seq = 881
current_ts = 399.723267
current_received_ts = 399.722656
current_seq = 882
count = 547
seq_step = 1
[397.722307] (kms_flip:9940) DEBUG: Vblank took 98us
[397.738813] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.723267
last_received_ts = 399.722656
last_seq = 882
current_ts = 399.739929
current_received_ts = 399.739258
current_seq = 883
count = 548
seq_step = 1
[397.738947] (kms_flip:9940) DEBUG: Vblank took 129us
[397.755632] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.739929
last_received_ts = 399.739258
last_seq = 883
current_ts = 399.756592
current_received_ts = 399.756073
current_seq = 884
count = 549
seq_step = 1
[397.755718] (kms_flip:9940) DEBUG: Vblank took 75us
[397.772216] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.756592
last_received_ts = 399.756073
last_seq = 884
current_ts = 399.773254
current_received_ts = 399.772675
current_seq = 885
count = 550
seq_step = 1
[397.772349] (kms_flip:9940) DEBUG: Vblank took 118us
[397.788838] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.773254
last_received_ts = 399.772675
last_seq = 885
current_ts = 399.789917
current_received_ts = 399.789307
current_seq = 886
count = 551
seq_step = 1
[397.788976] (kms_flip:9940) DEBUG: Vblank took 132us
[397.805648] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.789917
last_received_ts = 399.789307
last_seq = 886
current_ts = 399.806580
current_received_ts = 399.806091
current_seq = 887
count = 552
seq_step = 1
[397.805758] (kms_flip:9940) DEBUG: Vblank took 97us
[397.822196] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.806580
last_received_ts = 399.806091
last_seq = 887
current_ts = 399.823242
current_received_ts = 399.822632
current_seq = 888
count = 553
seq_step = 1
[397.822317] (kms_flip:9940) DEBUG: Vblank took 107us
[397.843312] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.823242
last_received_ts = 399.822632
last_seq = 888
current_ts = 399.839905
current_received_ts = 399.843719
current_seq = 889
count = 554
seq_step = 1
[397.843483] (kms_flip:9940) DEBUG: Vblank took 130us
[397.872863] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.839905
last_received_ts = 399.843719
last_seq = 889
current_ts = 399.873230
current_received_ts = 399.873291
current_seq = 891
count = 555
seq_step = 1
[397.872943] (kms_flip:9940) DEBUG: Vblank took 59us
[397.891648] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.873230
last_received_ts = 399.873291
last_seq = 891
current_ts = 399.889893
current_received_ts = 399.892090
current_seq = 892
count = 556
seq_step = 1
[397.891717] (kms_flip:9940) DEBUG: Vblank took 52us
[397.905518] (kms_flip:9940) DEBUG: name = flip
last_ts = 399.889893
last_received_ts = 399.892090
last_seq = 892
current_ts = 399.906586
current_received_ts = 399.905975
current_seq = 893
count = 557
seq_step = 1
[397.906445] (kms_flip:9940) DEBUG: Vblank took 914us
[397.906452] (kms_flip:9940) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[397.907654] (kms_flip:9940) CRITICAL: Failed assertion: end - start < 500
[397.916234] (kms_flip:9940) igt_core-INFO: Stack trace:
[397.923341] (kms_flip:9940) igt_core-INFO:   #0 ../lib/igt_core.c:2074 __igt_fail_assert()
[397.925438] (kms_flip:9940) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
[397.925789] (kms_flip:9940) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
[397.925848] (kms_flip:9940) igt_core-INFO:   #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
[397.925927] (kms_flip:9940) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
[397.973799] (kms_flip:9940) igt_core-INFO:   #5 ../sysdeps/nptl/libc_start_call_main.h:74 __libc_start_call_main()
[397.973898] (kms_flip:9940) igt_core-INFO:   #6 ../csu/libc-start.c:128 __libc_start_main@@GLIBC_2.34()
[397.974136] (kms_flip:9940) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-eDP1: FAIL (10.749s)
Subtest flip-vs-expired-vblank: FAIL (25.575s)
[399.296496] (kms_flip:9940) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2352:
[399.296609] (kms_flip:9940) igt_kms-CRITICAL: Failed assertion: found_it
[399.296654] (kms_flip:9940) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
[399.296699] (kms_flip:9940) igt_kms-CRITICAL: DPMS property not found on 393
Dmesg
<6> [433.709278] [IGT] kms_flip: starting dynamic subtest C-eDP1
<7> [433.713546] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:433]
<7> [433.725267] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:434]
<7> [433.803141] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [433.803579] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [433.805109] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [433.805458] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [433.805590] 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> [433.805810] 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> [433.806011] 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> [433.806206] 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> [433.806392] 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> [433.806577] 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> [433.806770] 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> [433.806950] 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> [433.807118] 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> [433.807275] 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> [433.807431] 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> [433.807580] 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> [433.807806] 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> [433.807980] 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> [433.808136] 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> [433.808275] 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> [433.808406] 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> [433.808540] 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> [433.808667] 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> [433.808815] 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> [433.808944] 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> [433.809066] 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> [433.809186] 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> [433.809303] 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> [433.809420] 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> [433.809534] 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> [433.809645] 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> [433.809757] 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> [433.809887] 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> [433.809997] 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> [433.810101] 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> [433.810204] 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> [433.810305] 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> [433.810404] 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> [433.810505] 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> [433.810612] 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> [433.810709] 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> [433.810820] 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> [433.810922] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] fastset requirement not met, forcing full modeset
<7> [433.811023] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:270:pipe B] releasing DPLL 0
<7> [433.811160] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [433.811243] 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> [433.811360] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:154:plane 1B] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0
<7> [433.811444] 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> [433.811517] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [433.811584] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] lines 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [433.811648] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] blocks 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [433.811711] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] 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> [433.811804] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:270:pipe B] data rate 0 num active planes 0
<7> [433.811919] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [433.812029] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [433.812125] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [433.812214] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [433.812302] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [433.812389] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:270:pipe B] min cdclk: 173855 kHz -> 0 kHz
<7> [433.812491] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz
<7> [433.812590] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [433.812681] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [433.812826] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [433.812960] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:270:pipe B] enable: no [modeset]
<7> [433.813069] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:154:plane 1B] fb: [NOFB], visible: no
<7> [433.813157] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:184:plane 2B] fb: [NOFB], visible: no
<7> [433.813246] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:214:plane 3B] fb: [NOFB], visible: no
<7> [433.813329] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:244:plane 4B] fb: [NOFB], visible: no
<7> [433.813413] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:254:plane 5B] fb: [NOFB], visible: no
<7> [433.813495] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:264:cursor B] fb: [NOFB], visible: no
<7> [433.813626] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2
<7> [433.814333] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [433.814448] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [434.020054] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [434.020742] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe B
<7> [434.032246] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [434.032732] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [434.032827] 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> [434.033336] 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> [434.033381] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [434.085217] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [434.085627] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [434.094181] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [434.094722] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:270:pipe B]
<7> [434.094878] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [434.095581] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [434.096501] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [434.097188] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [434.097898] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [434.098402] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [434.098860] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [434.099274] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [434.099725] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [434.100184] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [434.100614] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [434.101051] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [434.101478] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [434.101873] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [434.102273] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [434.102654] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [434.103057] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [434.103434] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [434.103948] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [434.104313] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [434.104699] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [434.105354] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_B
<7> [434.105860] 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> [434.106358] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [434.106885] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:270:pipe B]
<7> [434.107286] 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> [434.107713] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [434.108072] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [434.109052] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [434.109401] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [434.109461] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [434.109615] 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> [434.109990] 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> [434.110281] 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> [434.110548] xe 0000:00:02.0: [drm:intel_psr_compute_config [xe]] PSR2 not supported in transcoder C
<7> [434.110756] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:389:pipe C] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [434.111053] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:389:pipe C]
<7> [434.111368] 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> [434.111617] 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> [434.111862] 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> [434.112133] 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> [434.112354] 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> [434.112562] 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> [434.112761] 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> [434.112971] 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> [434.113187] 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> [434.113360] 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> [434.113530] 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> [434.113692] 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> [434.113902] 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> [434.114082] 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> [434.114233] 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> [434.114378] 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> [434.114514] 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> [434.114668] 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> [434.114826] 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> [434.114978] 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> [434.115111] 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> [434.115237] 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> [434.115359] 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> [434.115477] 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> [434.115609] 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> [434.115741] 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> [434.115870] 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> [434.115989] 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> [434.116104] 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> [434.116211] 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> [434.116317] 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> [434.116419] 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> [434.116519] 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> [434.116617] 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> [434.116714] 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> [434.116814] 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> [434.116917] 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> [434.117023] 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> [434.117140] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:389:pipe C] fastset requirement not met, forcing full modeset
<7> [434.117263] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no
<7> [434.117340] 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> [434.117442] 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> [434.117514] 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> [434.117584] 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> [434.117654] 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> [434.117716] 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> [434.117776] 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> [434.117878] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:389:pipe C] data rate 1390840 num active planes 1
<7> [434.118002] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [434.118112] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [434.118210] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [434.118301] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [434.118392] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [434.118499] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:389:pipe C] min cdclk: 0 kHz -> 173855 kHz
<7> [434.118599] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz
<7> [434.118682] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [434.118762] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [434.118862] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [434.118990] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:389:pipe C] allocated DPLL 0
<7> [434.119114] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:389:pipe C] reserving DPLL 0
<7> [434.119210] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:389:pipe C] enable: yes [modeset]
<7> [434.119293] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [434.119376] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: C, pipe bpp: 30, dithering: 0
<7> [434.119460] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [434.119542] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [434.119623] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [434.119704] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [434.119786] 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> [434.119900] 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> [434.120010] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [434.120113] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [434.120198] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: disabled, panel replay: disabled, selective fetch: disabled
<7> [434.120292] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [434.120375] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [434.120459] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 2, length 8
<7> [434.120541] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [434.120617] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [434.120692] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [434.120768] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [434.120865] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [434.120971] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [434.121074] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [434.121160] 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> [434.121241] 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> [434.121316] 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> [434.121391] 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> [434.121466] 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> [434.121540] 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> [434.121615] 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> [434.121689] 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> [434.121763] 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> [434.121861] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [434.121975] 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> [434.122075] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [434.122170] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [434.122260] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [434.122340] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [434.122420] 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> [434.122497] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [434.122571] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [434.122644] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [434.122717] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [434.122791] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [434.122933] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [434.122920] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [434.123035] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [434.123045] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [434.123136] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [434.123155] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [434.123237] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [434.123268] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [434.123329] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [434.123410] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [434.123485] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [434.123561] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [434.123642] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [434.123720] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [434.123801] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [434.123915] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [434.124016] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [434.124114] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [434.124211] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [434.124296] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [434.124377] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:273:plane 1C] fb: [FB:433] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [434.124461] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [434.124539] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [434.124615] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:303:plane 2C] fb: [NOFB], visible: no
<7> [434.124690] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:333:plane 3C] fb: [NOFB], visible: no
<7> [434.124766] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:363:plane 4C] fb: [NOFB], visible: no
<7> [434.124860] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:373:plane 5C] fb: [NOFB], visible: no
<7> [434.124963] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:383:cursor C] fb: [NOFB], visible: no
<7> [434.125269] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [434.125407] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_C
<7> [434.125556] 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> [434.125657] 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> [434.125751] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [434.125851] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [434.125975] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [434.126070] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [434.126158] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [434.126237] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [434.126312] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [434.126385] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [434.126456] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [434.126521] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [434.126587] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [434.126652] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [434.126716] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [434.126781] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [434.126871] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [434.126982] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xd
<7> [434.127172] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [434.127286] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [434.128606] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:389:pipe C]
<7> [434.128708] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [434.130759] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [434.130900] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (464 ms remaining)
<7> [434.604206] 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> [434.685961] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [434.686381] 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> [434.686746] 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> [434.722622] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [434.723053] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [434.723443] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [434.723946] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [434.899614] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [434.900120] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [434.900491] 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> [434.902648] 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> [434.904266] 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> [434.905295] 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> [434.906719] 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> [434.908389] 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> [434.909703] 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> [434.910237] 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> [434.911922] 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> [434.912389] 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> [434.913351] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe C
<7> [434.913985] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [434.914506] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe C
<7> [434.915129] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 4518
<7> [434.935417] xe 0000:00:02.0: [drm:intel_fbc_update [xe]] reserved 29491200 bytes of contiguous stolen space for FBC, limit: 1
<7> [434.936664] xe 0000:00:02.0: [drm:intel_fbc_update [xe]] Enabling FBC on [PLANE:273:plane 1C]
<7> [434.947599] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR1
<7> [434.950182] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [434.950697] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:389:pipe C]
<7> [437.476366] 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> [437.476877] 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> [444.459689] [IGT] kms_flip: finished subtest C-eDP1, FAIL
<6> [444.464806] [IGT] kms_flip: finished subtest flip-vs-expired-vblank, FAIL
<7> [444.485906] xe 0000:00:02.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:434] from all active usage due to RMFB ioctl
<7> [444.485999] xe 0000:00:02.0: [drm:atomic_remove_fb] Disabling [PLANE:273:plane 1C] because [FB:434] is removed
<7> [444.486096] 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> [444.486330] 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> [444.486494] 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> [444.486707] 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> [444.486869] 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> [444.487068] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:389:pipe C] data rate 0 num active planes 0
<7> [444.487310] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [444.487556] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [444.487785] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [444.488015] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [444.488288] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [444.489305] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR1
<7> [444.497258] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [444.497767] 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> [444.511567] xe 0000:00:02.0: [drm:__intel_fbc_disable [xe]] Disabling FBC on [PLANE:273:plane 1C]
<7> [444.539068] 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> [444.539684] 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> [444.540189] 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> [444.540792] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [444.541342] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]
<7> [444.541898] 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> [444.542377] 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> [444.542828] 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> [444.543271] 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> [444.543672] 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> [444.544059] 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> [444.544393] 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> [444.544733] 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> [444.545036] 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> [444.545320] 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> [444.545610] 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> [444.545883] 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> [444.546139] 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> [444.546378] 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> [444.546670] 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> [444.546894] 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> [444.547110] 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> [444.547317] 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> [444.547528] 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> [444.547727] 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> [444.547925] 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> [444.548151] 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> [444.548348] 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> [444.548566] 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> [444.548742] 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> [444.548916] 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> [444.549078] 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> [444.549234] 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> [444.549404] 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> [444.549650] 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> [444.549791] 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> [444.549930] 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> [444.550066] 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> [444.550197] 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> [444.550326] 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> [444.550450] 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> [444.550586] 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> [444.550705] 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> [444.550826] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [444.550944] 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> [444.551055] 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> [444.551162] 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> [444.551269] 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> [444.551375] 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> [444.551481] 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> [444.551595] 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> [444.551695] 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> [444.551793] 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> [444.551892] 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> [444.551986] 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> [444.552080] 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> [444.552175] 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> [444.552268] 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> [444.552361] 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> [444.552450] 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> [444.552543] 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> [444.552643] 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> [444.552744] 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> [444.552844] 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> [444.552928] 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> [444.553009] 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> [444.553087] 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> [444.553165] 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> [444.553241] 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> [444.553317] 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> [444.553393] 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> [444.553469] 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> [444.553606] 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> [444.553708] 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> [444.553806] 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> [444.553891] 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> [444.553972] 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> [444.554046] 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> [444.554120] 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> [444.554194] 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> [444.554268] 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> [444.554341] 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> [444.554415] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:389:pipe C] fastset requirement not met, forcing full modeset
<7> [444.554491] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:389:pipe C] releasing DPLL 0
<7> [444.554643] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xd -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [444.554728] 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> [444.554806] 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> [444.554879] 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> [444.554945] 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> [444.555005] 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> [444.555063] 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> [444.555121] 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> [444.555178] 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> [444.555235] 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> [444.555306] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1
<7> [444.555395] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [444.555482] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [444.555583] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [444.555676] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [444.555769] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [444.555861] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [444.555955] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:389:pipe C] min cdclk: 173855 kHz -> 0 kHz
<7> [444.556076] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0
<7> [444.556168] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0
<7> [444.556255] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [444.556342] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [444.556429] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [444.556519] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [444.556613] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [444.556704] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [444.556795] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [444.556885] 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> [444.556971] 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> [444.557054] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [444.557137] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [444.557218] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [444.557299] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [444.557378] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [444.557458] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [444.557552] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [444.557660] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [444.557763] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [444.557863] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [444.557948] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [444.558029] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [444.558111] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [444.558194] 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> [444.558276] 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> [444.558357] 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> [444.558439] 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> [444.558525] 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> [444.558615] 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> [444.558706] 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> [444.558793] 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> [444.558880] 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> [444.558961] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [444.559039] 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> [444.559116] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [444.559192] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [444.559269] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [444.559345] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [444.559423] 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> [444.559501] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [444.559612] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [444.559698] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [444.559780] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [444.559864] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [444.559948] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [444.560025] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [444.560101] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [444.560178] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [444.560255] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [444.560331] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [444.560406] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [444.560481] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [444.560571] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [444.560656] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [444.560742] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [444.560828] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [444.560914] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [444.560992] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [444.561069] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [444.561146] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [444.561223] 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> [444.561302] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [444.561379] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [444.561457] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [444.561542] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [444.561642] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [444.561741] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [444.561841] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [444.561925] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:389:pipe C] enable: no [modeset]
<7> [444.562003] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:273:plane 1C] fb: [NOFB], visible: no
<7> [444.562078] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:303:plane 2C] fb: [NOFB], visible: no
<7> [444.562153] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:333:plane 3C] fb: [NOFB], visible: no
<7> [444.562228] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:363:plane 4C] fb: [NOFB], visible: no
<7> [444.562303] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:373:plane 5C] fb: [NOFB], visible: no
<7> [444.562377] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:383:cursor C] fb: [NOFB], visible: no
<7> [444.562530] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [444.562692] 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> [444.562857] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [444.562945] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [444.764716] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [444.765294] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe C
<7> [444.778987] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [444.779354] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [444.779568] 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> [444.780011] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [444.780105] 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> [444.832053] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [444.832533] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [444.841104] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [444.841660] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x4, on? 1) for [CRTC:389:pipe C]
<7> [444.841800] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [444.842373] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [444.843318] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [444.843958] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [444.844586] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [444.845011] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [444.845361] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [444.845788] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [444.846145] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [444.846463] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [444.846830] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [444.847148] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [444.847481] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [444.847858] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [444.848252] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [444.848619] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [444.848972] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [444.849359] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [444.849895] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [444.850227] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [444.850628] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [444.852418] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]
<7> [444.853027] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [444.855812] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [444.856202] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (486 ms remaining)
<7> [444.869640] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [444.870158] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [444.870631] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [444.871204] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [445.348776] 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> [445.399986] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [445.400386] 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> [445.400796] 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> [445.436586] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [445.437080] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [445.437567] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [445.438078] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [445.614078] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [445.614476] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [445.614904] 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> [445.616999] 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> [445.618558] 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> [445.619358] 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> [445.620566] 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> [445.621940] 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> [445.623030] 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> [445.623418] 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> [445.624935] 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> [445.625312] 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> [445.626204] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [445.626743] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [445.627147] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [445.627586] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 4518
<7> [445.660500] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [445.662240] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [445.662642] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [445.665638] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_C
<7> [445.666123] 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> [445.666656] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [445.667211] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:389:pipe C]
<7> [445.667845] xe 0000:00:02.0: [drm:drm_client_dev_restore] fbdev: ret=0
<6> [445.669875] [IGT] kms_flip: exiting, ret=98
<7> [445.685552] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [445.685729] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [445.685828] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
Created at 2026-05-15 17:11:23