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

Result: Fail

i915_display_info7 igt_runner7 results7.json results7-xe-load.json guc_logs7.tar i915_display_info_post_exec7 boot7 dmesg7

DetailValue
Duration 10.40 seconds
Hostname 
shard-lnl-2
Igt-Version 
IGT-Version: 2.3-g16ce286ca (x86_64) (Linux: 6.19.0-rc6-lgci-xe-xe-4428-dc0b90be8d513256a+ x86_64)
Out 
Starting dynamic subtest: C-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1889 run_test()
  #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
  #4 ../tests/kms_flip.c:2045 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest C-eDP1: FAIL (10.402s)
Subtest flip-vs-expired-vblank: FAIL (32.856s)
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2386 kmstest_set_connector_dpms()
  #2 ../lib/igt_core.c:2961 igt_atexit_handler()
  #3 [erand48_r+0x1d6]
  #4 [exit+0x1e]
  #5 ../lib/igt_core.c:2416 igt_exit()
  #6 [main+0x3f]
  #7 [__libc_init_first+0x8a]
  #8 [__libc_start_main+0x8b]
  #9 [_start+0x25]
Err 
Starting dynamic subtest: C-eDP1
(kms_flip:9433) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:9433) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest C-eDP1 failed.
**** DEBUG ****
(kms_flip:9433) DEBUG: name = flip
last_ts = 476.984528
last_received_ts = 476.984039
last_seq = 962
current_ts = 477.001190
current_received_ts = 477.000641
current_seq = 963
count = 420
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.001190
last_received_ts = 477.000641
last_seq = 963
current_ts = 477.017853
current_received_ts = 477.017334
current_seq = 964
count = 421
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.017853
last_received_ts = 477.017334
last_seq = 964
current_ts = 477.034515
current_received_ts = 477.033936
current_seq = 965
count = 422
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 126us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.034515
last_received_ts = 477.033936
last_seq = 965
current_ts = 477.051147
current_received_ts = 477.050629
current_seq = 966
count = 423
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.051147
last_received_ts = 477.050629
last_seq = 966
current_ts = 477.067810
current_received_ts = 477.067261
current_seq = 967
count = 424
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.067810
last_received_ts = 477.067261
last_seq = 967
current_ts = 477.084473
current_received_ts = 477.083923
current_seq = 968
count = 425
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 141us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.084473
last_received_ts = 477.083923
last_seq = 968
current_ts = 477.101135
current_received_ts = 477.100616
current_seq = 969
count = 426
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.101135
last_received_ts = 477.100616
last_seq = 969
current_ts = 477.117767
current_received_ts = 477.117188
current_seq = 970
count = 427
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 97us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.117767
last_received_ts = 477.117188
last_seq = 970
current_ts = 477.134430
current_received_ts = 477.133911
current_seq = 971
count = 428
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 117us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.134430
last_received_ts = 477.133911
last_seq = 971
current_ts = 477.151093
current_received_ts = 477.150543
current_seq = 972
count = 429
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.151093
last_received_ts = 477.150543
last_seq = 972
current_ts = 477.167755
current_received_ts = 477.167175
current_seq = 973
count = 430
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.167755
last_received_ts = 477.167175
last_seq = 973
current_ts = 477.184387
current_received_ts = 477.183838
current_seq = 974
count = 431
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.184387
last_received_ts = 477.183838
last_seq = 974
current_ts = 477.201050
current_received_ts = 477.200500
current_seq = 975
count = 432
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.201050
last_received_ts = 477.200500
last_seq = 975
current_ts = 477.217712
current_received_ts = 477.217163
current_seq = 976
count = 433
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.217712
last_received_ts = 477.217163
last_seq = 976
current_ts = 477.234375
current_received_ts = 477.233826
current_seq = 977
count = 434
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.234375
last_received_ts = 477.233826
last_seq = 977
current_ts = 477.251038
current_received_ts = 477.250488
current_seq = 978
count = 435
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.251038
last_received_ts = 477.250488
last_seq = 978
current_ts = 477.267670
current_received_ts = 477.267151
current_seq = 979
count = 436
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 102us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.267670
last_received_ts = 477.267151
last_seq = 979
current_ts = 477.284332
current_received_ts = 477.283813
current_seq = 980
count = 437
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 104us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.284332
last_received_ts = 477.283813
last_seq = 980
current_ts = 477.300995
current_received_ts = 477.300446
current_seq = 981
count = 438
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.300995
last_received_ts = 477.300446
last_seq = 981
current_ts = 477.317627
current_received_ts = 477.317108
current_seq = 982
count = 439
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.317627
last_received_ts = 477.317108
last_seq = 982
current_ts = 477.334290
current_received_ts = 477.333771
current_seq = 983
count = 440
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.334290
last_received_ts = 477.333771
last_seq = 983
current_ts = 477.350952
current_received_ts = 477.350372
current_seq = 984
count = 441
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.350952
last_received_ts = 477.350372
last_seq = 984
current_ts = 477.367615
current_received_ts = 477.367096
current_seq = 985
count = 442
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.367615
last_received_ts = 477.367096
last_seq = 985
current_ts = 477.384247
current_received_ts = 477.383728
current_seq = 986
count = 443
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.384247
last_received_ts = 477.383728
last_seq = 986
current_ts = 477.400909
current_received_ts = 477.400330
current_seq = 987
count = 444
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.400909
last_received_ts = 477.400330
last_seq = 987
current_ts = 477.417572
current_received_ts = 477.417053
current_seq = 988
count = 445
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 86us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.417572
last_received_ts = 477.417053
last_seq = 988
current_ts = 477.434235
current_received_ts = 477.433685
current_seq = 989
count = 446
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.434235
last_received_ts = 477.433685
last_seq = 989
current_ts = 477.450867
current_received_ts = 477.450317
current_seq = 990
count = 447
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.450867
last_received_ts = 477.450317
last_seq = 990
current_ts = 477.467529
current_received_ts = 477.466980
current_seq = 991
count = 448
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 89us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.467529
last_received_ts = 477.466980
last_seq = 991
current_ts = 477.484192
current_received_ts = 477.483643
current_seq = 992
count = 449
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.484192
last_received_ts = 477.483643
last_seq = 992
current_ts = 477.500854
current_received_ts = 477.500214
current_seq = 993
count = 450
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.500854
last_received_ts = 477.500214
last_seq = 993
current_ts = 477.517517
current_received_ts = 477.516998
current_seq = 994
count = 451
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 97us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.517517
last_received_ts = 477.516998
last_seq = 994
current_ts = 477.534149
current_received_ts = 477.533630
current_seq = 995
count = 452
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 97us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.534149
last_received_ts = 477.533630
last_seq = 995
current_ts = 477.550812
current_received_ts = 477.550201
current_seq = 996
count = 453
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.550812
last_received_ts = 477.550201
last_seq = 996
current_ts = 477.567474
current_received_ts = 477.566925
current_seq = 997
count = 454
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 110us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.567474
last_received_ts = 477.566925
last_seq = 997
current_ts = 477.584137
current_received_ts = 477.583588
current_seq = 998
count = 455
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.584137
last_received_ts = 477.583588
last_seq = 998
current_ts = 477.600769
current_received_ts = 477.600189
current_seq = 999
count = 456
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 93us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.600769
last_received_ts = 477.600189
last_seq = 999
current_ts = 477.617432
current_received_ts = 477.616913
current_seq = 1000
count = 457
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 127us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.617432
last_received_ts = 477.616913
last_seq = 1000
current_ts = 477.634094
current_received_ts = 477.633545
current_seq = 1001
count = 458
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.634094
last_received_ts = 477.633545
last_seq = 1001
current_ts = 477.650757
current_received_ts = 477.650177
current_seq = 1002
count = 459
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.650757
last_received_ts = 477.650177
last_seq = 1002
current_ts = 477.667389
current_received_ts = 477.666870
current_seq = 1003
count = 460
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 129us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.667389
last_received_ts = 477.666870
last_seq = 1003
current_ts = 477.684052
current_received_ts = 477.683502
current_seq = 1004
count = 461
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 86us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.684052
last_received_ts = 477.683502
last_seq = 1004
current_ts = 477.700714
current_received_ts = 477.700195
current_seq = 1005
count = 462
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.700714
last_received_ts = 477.700195
last_seq = 1005
current_ts = 477.717377
current_received_ts = 477.716827
current_seq = 1006
count = 463
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.717377
last_received_ts = 477.716827
last_seq = 1006
current_ts = 477.734039
current_received_ts = 477.733459
current_seq = 1007
count = 464
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.734039
last_received_ts = 477.733459
last_seq = 1007
current_ts = 477.750671
current_received_ts = 477.750000
current_seq = 1008
count = 465
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 62us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.750671
last_received_ts = 477.750000
last_seq = 1008
current_ts = 477.767334
current_received_ts = 477.766785
current_seq = 1009
count = 466
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 56us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.767334
last_received_ts = 477.766785
last_seq = 1009
current_ts = 477.783997
current_received_ts = 477.783417
current_seq = 1010
count = 467
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.783997
last_received_ts = 477.783417
last_seq = 1010
current_ts = 477.800629
current_received_ts = 477.800140
current_seq = 1011
count = 468
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 90us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.800629
last_received_ts = 477.800140
last_seq = 1011
current_ts = 477.817291
current_received_ts = 477.816772
current_seq = 1012
count = 469
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.817291
last_received_ts = 477.816772
last_seq = 1012
current_ts = 477.833954
current_received_ts = 477.833405
current_seq = 1013
count = 470
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.833954
last_received_ts = 477.833405
last_seq = 1013
current_ts = 477.850616
current_received_ts = 477.850098
current_seq = 1014
count = 471
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.850616
last_received_ts = 477.850098
last_seq = 1014
current_ts = 477.867249
current_received_ts = 477.866730
current_seq = 1015
count = 472
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.867249
last_received_ts = 477.866730
last_seq = 1015
current_ts = 477.883911
current_received_ts = 477.883392
current_seq = 1016
count = 473
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 102us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.883911
last_received_ts = 477.883392
last_seq = 1016
current_ts = 477.900574
current_received_ts = 477.900055
current_seq = 1017
count = 474
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.900574
last_received_ts = 477.900055
last_seq = 1017
current_ts = 477.917236
current_received_ts = 477.916687
current_seq = 1018
count = 475
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 89us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.917236
last_received_ts = 477.916687
last_seq = 1018
current_ts = 477.933899
current_received_ts = 477.933319
current_seq = 1019
count = 476
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.933899
last_received_ts = 477.933319
last_seq = 1019
current_ts = 477.950562
current_received_ts = 477.950043
current_seq = 1020
count = 477
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.950562
last_received_ts = 477.950043
last_seq = 1020
current_ts = 477.967194
current_received_ts = 477.966644
current_seq = 1021
count = 478
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 97us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.967194
last_received_ts = 477.966644
last_seq = 1021
current_ts = 477.983856
current_received_ts = 477.983276
current_seq = 1022
count = 479
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 477.983856
last_received_ts = 477.983276
last_seq = 1022
current_ts = 478.000519
current_received_ts = 477.999969
current_seq = 1023
count = 480
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 130us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.000519
last_received_ts = 477.999969
last_seq = 1023
current_ts = 478.017151
current_received_ts = 478.016632
current_seq = 1024
count = 481
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.017151
last_received_ts = 478.016632
last_seq = 1024
current_ts = 478.033813
current_received_ts = 478.033203
current_seq = 1025
count = 482
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 95us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.033813
last_received_ts = 478.033203
last_seq = 1025
current_ts = 478.050476
current_received_ts = 478.049927
current_seq = 1026
count = 483
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 116us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.050476
last_received_ts = 478.049927
last_seq = 1026
current_ts = 478.067139
current_received_ts = 478.066589
current_seq = 1027
count = 484
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.067139
last_received_ts = 478.066589
last_seq = 1027
current_ts = 478.083771
current_received_ts = 478.083252
current_seq = 1028
count = 485
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 168us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.083771
last_received_ts = 478.083252
last_seq = 1028
current_ts = 478.100433
current_received_ts = 478.099884
current_seq = 1029
count = 486
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 111us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.100433
last_received_ts = 478.099884
last_seq = 1029
current_ts = 478.117096
current_received_ts = 478.116547
current_seq = 1030
count = 487
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.117096
last_received_ts = 478.116547
last_seq = 1030
current_ts = 478.133759
current_received_ts = 478.133179
current_seq = 1031
count = 488
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 96us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.133759
last_received_ts = 478.133179
last_seq = 1031
current_ts = 478.150421
current_received_ts = 478.149902
current_seq = 1032
count = 489
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 133us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.150421
last_received_ts = 478.149902
last_seq = 1032
current_ts = 478.167053
current_received_ts = 478.166504
current_seq = 1033
count = 490
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.167053
last_received_ts = 478.166504
last_seq = 1033
current_ts = 478.183716
current_received_ts = 478.183167
current_seq = 1034
count = 491
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 98us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.183716
last_received_ts = 478.183167
last_seq = 1034
current_ts = 478.200378
current_received_ts = 478.199829
current_seq = 1035
count = 492
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.200378
last_received_ts = 478.199829
last_seq = 1035
current_ts = 478.217041
current_received_ts = 478.216431
current_seq = 1036
count = 493
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.217041
last_received_ts = 478.216431
last_seq = 1036
current_ts = 478.233673
current_received_ts = 478.233154
current_seq = 1037
count = 494
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 97us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.233673
last_received_ts = 478.233154
last_seq = 1037
current_ts = 478.250336
current_received_ts = 478.249817
current_seq = 1038
count = 495
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.250336
last_received_ts = 478.249817
last_seq = 1038
current_ts = 478.266998
current_received_ts = 478.266418
current_seq = 1039
count = 496
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.266998
last_received_ts = 478.266418
last_seq = 1039
current_ts = 478.283661
current_received_ts = 478.283112
current_seq = 1040
count = 497
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.283661
last_received_ts = 478.283112
last_seq = 1040
current_ts = 478.300293
current_received_ts = 478.299774
current_seq = 1041
count = 498
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.300293
last_received_ts = 478.299774
last_seq = 1041
current_ts = 478.316956
current_received_ts = 478.316406
current_seq = 1042
count = 499
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.316956
last_received_ts = 478.316406
last_seq = 1042
current_ts = 478.333618
current_received_ts = 478.333099
current_seq = 1043
count = 500
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.333618
last_received_ts = 478.333099
last_seq = 1043
current_ts = 478.350281
current_received_ts = 478.349731
current_seq = 1044
count = 501
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.350281
last_received_ts = 478.349731
last_seq = 1044
current_ts = 478.366913
current_received_ts = 478.366394
current_seq = 1045
count = 502
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.366913
last_received_ts = 478.366394
last_seq = 1045
current_ts = 478.383575
current_received_ts = 478.383087
current_seq = 1046
count = 503
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 96us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.383575
last_received_ts = 478.383087
last_seq = 1046
current_ts = 478.400238
current_received_ts = 478.399689
current_seq = 1047
count = 504
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.400238
last_received_ts = 478.399689
last_seq = 1047
current_ts = 478.416901
current_received_ts = 478.416351
current_seq = 1048
count = 505
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 96us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.416901
last_received_ts = 478.416351
last_seq = 1048
current_ts = 478.433563
current_received_ts = 478.432983
current_seq = 1049
count = 506
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.433563
last_received_ts = 478.432983
last_seq = 1049
current_ts = 478.450195
current_received_ts = 478.449677
current_seq = 1050
count = 507
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.450195
last_received_ts = 478.449677
last_seq = 1050
current_ts = 478.466858
current_received_ts = 478.466339
current_seq = 1051
count = 508
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.466858
last_received_ts = 478.466339
last_seq = 1051
current_ts = 478.483521
current_received_ts = 478.482971
current_seq = 1052
count = 509
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.483521
last_received_ts = 478.482971
last_seq = 1052
current_ts = 478.500153
current_received_ts = 478.499634
current_seq = 1053
count = 510
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.500153
last_received_ts = 478.499634
last_seq = 1053
current_ts = 478.516815
current_received_ts = 478.516205
current_seq = 1054
count = 511
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.516815
last_received_ts = 478.516205
last_seq = 1054
current_ts = 478.533478
current_received_ts = 478.532959
current_seq = 1055
count = 512
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 111us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.533478
last_received_ts = 478.532959
last_seq = 1055
current_ts = 478.550140
current_received_ts = 478.549591
current_seq = 1056
count = 513
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.550140
last_received_ts = 478.549591
last_seq = 1056
current_ts = 478.566803
current_received_ts = 478.566193
current_seq = 1057
count = 514
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.566803
last_received_ts = 478.566193
last_seq = 1057
current_ts = 478.583435
current_received_ts = 478.582916
current_seq = 1058
count = 515
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 128us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.583435
last_received_ts = 478.582916
last_seq = 1058
current_ts = 478.600098
current_received_ts = 478.599548
current_seq = 1059
count = 516
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.600098
last_received_ts = 478.599548
last_seq = 1059
current_ts = 478.616760
current_received_ts = 478.616180
current_seq = 1060
count = 517
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.616760
last_received_ts = 478.616180
last_seq = 1060
current_ts = 478.633423
current_received_ts = 478.632874
current_seq = 1061
count = 518
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 151us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.633423
last_received_ts = 478.632874
last_seq = 1061
current_ts = 478.650055
current_received_ts = 478.649536
current_seq = 1062
count = 519
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.650055
last_received_ts = 478.649536
last_seq = 1062
current_ts = 478.666718
current_received_ts = 478.666168
current_seq = 1063
count = 520
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.666718
last_received_ts = 478.666168
last_seq = 1063
current_ts = 478.683380
current_received_ts = 478.682831
current_seq = 1064
count = 521
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 92us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.683380
last_received_ts = 478.682831
last_seq = 1064
current_ts = 478.700043
current_received_ts = 478.699432
current_seq = 1065
count = 522
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.700043
last_received_ts = 478.699432
last_seq = 1065
current_ts = 478.716675
current_received_ts = 478.716187
current_seq = 1066
count = 523
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.716675
last_received_ts = 478.716187
last_seq = 1066
current_ts = 478.733337
current_received_ts = 478.732819
current_seq = 1067
count = 524
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 98us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.733337
last_received_ts = 478.732819
last_seq = 1067
current_ts = 478.750000
current_received_ts = 478.749420
current_seq = 1068
count = 525
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.750000
last_received_ts = 478.749420
last_seq = 1068
current_ts = 478.766663
current_received_ts = 478.766144
current_seq = 1069
count = 526
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.766663
last_received_ts = 478.766144
last_seq = 1069
current_ts = 478.783295
current_received_ts = 478.782806
current_seq = 1070
count = 527
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.783295
last_received_ts = 478.782806
last_seq = 1070
current_ts = 478.799957
current_received_ts = 478.799377
current_seq = 1071
count = 528
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 98us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.799957
last_received_ts = 478.799377
last_seq = 1071
current_ts = 478.816620
current_received_ts = 478.816101
current_seq = 1072
count = 529
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.816620
last_received_ts = 478.816101
last_seq = 1072
current_ts = 478.833282
current_received_ts = 478.832733
current_seq = 1073
count = 530
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.833282
last_received_ts = 478.832733
last_seq = 1073
current_ts = 478.849915
current_received_ts = 478.849335
current_seq = 1074
count = 531
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 101us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.849915
last_received_ts = 478.849335
last_seq = 1074
current_ts = 478.866577
current_received_ts = 478.866058
current_seq = 1075
count = 532
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 95us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.866577
last_received_ts = 478.866058
last_seq = 1075
current_ts = 478.883240
current_received_ts = 478.882721
current_seq = 1076
count = 533
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 92us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.883240
last_received_ts = 478.882721
last_seq = 1076
current_ts = 478.899902
current_received_ts = 478.899323
current_seq = 1077
count = 534
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.899902
last_received_ts = 478.899323
last_seq = 1077
current_ts = 478.916565
current_received_ts = 478.916046
current_seq = 1078
count = 535
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 87us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.916565
last_received_ts = 478.916046
last_seq = 1078
current_ts = 478.933197
current_received_ts = 478.932678
current_seq = 1079
count = 536
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 99us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.933197
last_received_ts = 478.932678
last_seq = 1079
current_ts = 478.949860
current_received_ts = 478.949310
current_seq = 1080
count = 537
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.949860
last_received_ts = 478.949310
last_seq = 1080
current_ts = 478.966522
current_received_ts = 478.966034
current_seq = 1081
count = 538
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 98us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.966522
last_received_ts = 478.966034
last_seq = 1081
current_ts = 478.983185
current_received_ts = 478.982635
current_seq = 1082
count = 539
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 100us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.983185
last_received_ts = 478.982635
last_seq = 1082
current_ts = 478.999817
current_received_ts = 478.999176
current_seq = 1083
count = 540
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 88us
(kms_flip:9433) DEBUG: name = flip
last_ts = 478.999817
last_received_ts = 478.999176
last_seq = 1083
current_ts = 479.016479
current_received_ts = 479.015961
current_seq = 1084
count = 541
seq_step = 1
(kms_flip:9433) DEBUG: Vblank took 617us
(kms_flip:9433) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:9433) CRITICAL: Failed assertion: end - start < 500
(kms_flip:9433) igt_core-INFO: Stack trace:
(kms_flip:9433) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:9433) igt_core-INFO:   #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
(kms_flip:9433) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:9433) igt_core-INFO:   #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
(kms_flip:9433) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:9433) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:9433) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:9433) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-eDP1: FAIL (10.402s)
Subtest flip-vs-expired-vblank: FAIL (32.856s)
(kms_flip:9433) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2386:
(kms_flip:9433) igt_kms-CRITICAL: Failed assertion: found_it
(kms_flip:9433) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
(kms_flip:9433) igt_kms-CRITICAL: DPMS property not found on 391
Dmesg
<6> [498.857360] [IGT] kms_flip: starting dynamic subtest C-eDP1
<7> [498.859678] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:428]
<7> [498.861371] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430]
<7> [498.868601] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [498.869021] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [498.869364] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [498.935999] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A]
<7> [498.936214] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [498.936468] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [498.936909] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]
<7> [498.937040] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [498.937270] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [498.937464] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [498.937676] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [498.937862] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268: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> [498.938041] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [498.938212] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [498.938379] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [498.938543] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [498.938724] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [498.938880] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [498.939031] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [498.939179] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [498.939331] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [498.939477] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [498.939632] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [498.939771] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [498.939908] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [498.940042] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [498.940172] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [498.940296] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [498.940418] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [498.940538] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [498.940689] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [498.940826] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [498.940941] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [498.941054] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [498.941164] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [498.941270] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [498.941375] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [498.941478] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [498.941603] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [498.941721] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [498.941821] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [498.941924] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [498.942025] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [498.942123] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [498.942222] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [498.942323] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:268:pipe B] fastset requirement not met, forcing full modeset
<7> [498.942424] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:268:pipe B] releasing DPLL 0
<7> [498.942565] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [498.942706] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:268:pipe B] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [498.942828] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:262:cursor B] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0
<7> [498.942923] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:268:pipe B] min cdclk: 173855 kHz -> 0 kHz
<7> [498.943054] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [498.943157] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [498.943253] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [498.943369] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:268:pipe B] enable: no [modeset]
<7> [498.943461] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:152:plane 1B] fb: [NOFB], visible: no
<7> [498.943551] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:182:plane 2B] fb: [NOFB], visible: no
<7> [498.943660] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:212:plane 3B] fb: [NOFB], visible: no
<7> [498.943753] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:242:plane 4B] fb: [NOFB], visible: no
<7> [498.943840] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:252:plane 5B] fb: [NOFB], visible: no
<7> [498.943930] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:262:cursor B] fb: [NOFB], visible: no
<7> [498.944179] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [498.944326] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [499.146004] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 0
<7> [499.146585] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe B
<7> [499.152151] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turn panel power off
<7> [499.152660] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [499.153230] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [499.204501] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [499.204937] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:268:pipe B]
<7> [499.205050] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [499.205422] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - short
<7> [499.206218] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [499.206112] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:390:DDI A/PHY A]
<7> [499.206694] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [499.207307] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:390:DDI A/PHY A]
<7> [499.207711] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:399:DDI TC1/PHY TC1]
<7> [499.208146] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DP-MST A]
<7> [499.208584] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST B]
<7> [499.209029] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST C]
<7> [499.209397] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:411:DDI TC2/PHY TC2]
<7> [499.209775] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DP-MST A]
<7> [499.210130] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST B]
<7> [499.210515] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST C]
<7> [499.210906] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:419:DDI TC3/PHY TC3]
<7> [499.211246] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DP-MST A]
<7> [499.211575] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST B]
<7> [499.212001] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST C]
<7> [499.212343] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:391:eDP-1]
<7> [499.212791] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [499.213087] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [499.213374] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [499.213915] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_B
<7> [499.214406] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [499.214901] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:268:pipe B]
<7> [499.215293] 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> [499.215800] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [499.216150] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [499.217139] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [499.217591] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]
<7> [499.217675] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:391:eDP-1]
<7> [499.217911] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:391:eDP-1] Limiting display bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [499.218361] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:390:DDI A/PHY A][CRTC:387: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> [499.218743] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 link rate required 1303913 available 1728000
<7> [499.219096] xe 0000:00:02.0: [drm:intel_psr_compute_config [xe]] PSR2 not supported in transcoder C
<7> [499.219379] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:387:pipe C] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [499.219710] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:390:DDI A/PHY A] [CRTC:387:pipe C]
<7> [499.220119] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.enable (expected no, found yes)
<7> [499.220430] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.active (expected no, found yes)
<7> [499.220797] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)
<7> [499.221109] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in lane_count (expected 0, found 4)
<7> [499.221377] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387: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> [499.221624] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [499.221899] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [499.222192] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [499.222423] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [499.222677] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [499.222922] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [499.223121] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [499.223319] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [499.223504] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [499.223689] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [499.223904] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [499.224112] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [499.224297] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [499.224469] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [499.224627] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [499.224798] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [499.224956] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [499.225109] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [499.225252] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [499.225389] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [499.225526] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [499.225663] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [499.225822] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [499.225964] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [499.226094] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [499.226221] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [499.226343] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [499.226480] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [499.226616] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [499.226747] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [499.226860] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [499.226973] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [499.227082] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [499.227186] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset
<7> [499.227314] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no
<7> [499.227411] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:387:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4
<7> [499.227528] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:271:plane 1C] ddb ( 0 - 0) -> ( 0 - 2003), size 0 -> 2003
<7> [499.227619] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:381:cursor C] ddb ( 0 - 0) -> (2003 - 2048), size 0 -> 45
<7> [499.227701] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:271: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> [499.227793] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:271: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> [499.227869] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:271: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> [499.227950] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:271: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> [499.228053] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:387:pipe C] data rate 1390840 num active planes 1
<7> [499.228166] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [499.228265] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [499.228361] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [499.228453] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [499.228542] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [499.228653] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:387:pipe C] min cdclk: 0 kHz -> 173855 kHz
<7> [499.228839] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [499.228956] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [499.229064] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [499.229174] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:387:pipe C] allocated DPLL 0
<7> [499.229253] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:387:pipe C] reserving DPLL 0
<7> [499.229331] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:387:pipe C] enable: yes [modeset]
<7> [499.229410] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [499.229489] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: C, pipe bpp: 30, dithering: 0
<7> [499.229576] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [499.229656] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [499.229740] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [499.229838] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [499.229933] 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> [499.230027] 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> [499.230114] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [499.230185] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [499.230254] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: disabled, panel replay: disabled, selective fetch: disabled
<7> [499.230324] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0
<7> [499.230393] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [499.230463] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 2, length 8
<7> [499.230532] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [499.230600] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [499.230668] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [499.230742] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [499.230827] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [499.230916] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [499.231013] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [499.231103] 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> [499.231180] 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> [499.231258] 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> [499.231327] 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> [499.231394] 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> [499.231461] 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> [499.231529] 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> [499.231599] 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> [499.231669] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855
<7> [499.231750] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [499.231849] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [499.231946] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [499.232039] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [499.232114] 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> [499.232188] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [499.232262] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [499.232343] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [499.232428] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [499.232512] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [499.232588] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [499.232655] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [499.232727] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [499.232843] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [499.232952] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [499.233047] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [499.233120] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [499.233194] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [499.233264] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [499.233330] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [499.233396] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [499.233461] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [499.233527] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [499.233592] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [499.233658] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [499.233726] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [499.233832] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [499.233936] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:271:plane 1C] fb: [FB:428] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [499.234034] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [499.234117] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [499.234205] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:301:plane 2C] fb: [NOFB], visible: no
<7> [499.234281] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:331:plane 3C] fb: [NOFB], visible: no
<7> [499.234356] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:361:plane 4C] fb: [NOFB], visible: no
<7> [499.234431] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:371:plane 5C] fb: [NOFB], visible: no
<7> [499.234499] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:381:cursor C] fb: [NOFB], visible: no
<7> [499.234770] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [499.235003] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [499.235129] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [499.235255] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling always-on
<7> [499.235343] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling always-on
<7> [499.235430] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [499.235520] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [499.235661] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [499.235801] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_C
<7> [499.235958] 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> [499.236064] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [499.236149] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [499.236225] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:390:DDI A/PHY A]
<7> [499.236288] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:399:DDI TC1/PHY TC1]
<7> [499.236350] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DP-MST A]
<7> [499.236413] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST B]
<7> [499.236478] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST C]
<7> [499.236540] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:411:DDI TC2/PHY TC2]
<7> [499.236601] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DP-MST A]
<7> [499.236660] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST B]
<7> [499.236724] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST C]
<7> [499.236816] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:419:DDI TC3/PHY TC3]
<7> [499.236891] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DP-MST A]
<7> [499.236964] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST B]
<7> [499.237033] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST C]
<7> [499.237119] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xd
<7> [499.237289] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [499.237401] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [499.238825] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:387:pipe C]
<7> [499.238960] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [499.240685] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turn panel power on
<7> [499.240786] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power cycle (465 ms remaining)
<7> [499.243026] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [499.243113] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - long
<7> [499.243183] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [499.243311] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:390:DDI A/PHY A]
<7> [499.714242] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [499.755276] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [499.755708] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power on
<7> [499.756148] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [499.791858] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [499.792363] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - long
<7> [499.792858] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [499.793415] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:390:DDI A/PHY A]
<7> [499.969383] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [499.969758] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turning VDD on
<7> [499.970064] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [499.972241] 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> [499.973566] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [499.974435] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [499.975755] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [499.977010] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [499.978250] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Clock recovery OK
<7> [499.978629] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [499.980311] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [499.980792] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [499.981688] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe C
<7> [499.982265] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [499.982696] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe C
<7> [499.983181] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 4518
<7> [499.984746] xe 0000:00:02.0: [drm:intel_fbc_update [xe]] reserved 14745600 bytes of contiguous stolen space for FBC, limit: 2
<7> [499.985173] xe 0000:00:02.0: [drm:intel_fbc_update [xe]] Enabling FBC on [PLANE:271:plane 1C]
<7> [499.999287] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR1
<7> [500.000864] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:391:eDP-1]
<7> [500.001669] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:387:pipe C]
<7> [502.547797] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turning VDD off
<7> [502.548318] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<6> [509.260745] [IGT] kms_flip: finished subtest C-eDP1, FAIL
<6> [509.266371] [IGT] kms_flip: finished subtest flip-vs-expired-vblank, FAIL
<7> [509.283609] xe 0000:00:02.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:430] from all active usage due to RMFB ioctl
<7> [509.284223] xe 0000:00:02.0: [drm:atomic_remove_fb] Disabling [PLANE:271:plane 1C] because [FB:430] is removed
<7> [509.284316] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:271:plane 1C] ddb ( 0 - 2003) -> ( 0 - 0), size 2003 -> 0
<7> [509.284508] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:271: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> [509.284665] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:271: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> [509.284799] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:271: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> [509.284923] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:271: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> [509.285114] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:387:pipe C] data rate 0 num active planes 0
<7> [509.285309] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [509.285494] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [509.285669] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [509.285836] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [509.286000] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [509.287898] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR1
<7> [509.298169] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turning VDD on
<7> [509.298387] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f
<7> [509.310129] xe 0000:00:02.0: [drm:__intel_fbc_disable [xe]] Disabling FBC on [PLANE:271:plane 1C]
<7> [509.340207] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:391:eDP-1] Limiting display bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [509.340736] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:390:DDI A/PHY A][CRTC:149: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> [509.341149] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 link rate required 1303913 available 1728000
<7> [509.341502] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [509.341863] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:390:DDI A/PHY A] [CRTC:149:pipe A]
<7> [509.342196] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [509.342490] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [509.342770] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [509.343036] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [509.343306] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149: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> [509.343555] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [509.343799] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [509.344042] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [509.344350] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [509.344567] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [509.344783] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [509.344997] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [509.345208] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [509.345404] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [509.345600] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [509.345784] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [509.345966] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [509.346145] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [509.346317] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [509.346481] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [509.346645] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [509.346805] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [509.346965] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [509.347124] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [509.347273] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [509.347417] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [509.347558] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [509.347698] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [509.347835] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [509.347971] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [509.348107] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [509.348238] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [509.348362] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [509.348484] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [509.348608] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [509.348727] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [509.348845] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [509.348963] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [509.349082] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] fastset requirement not met, forcing full modeset
<7> [509.349192] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.enable (expected yes, found no)
<7> [509.349300] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.active (expected yes, found no)
<7> [509.349405] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1)
<7> [509.349508] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in lane_count (expected 4, found 0)
<7> [509.349610] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387: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> [509.349717] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [509.349823] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [509.349927] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [509.350030] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [509.350188] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [509.350293] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [509.350396] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [509.350500] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [509.350606] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [509.350711] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [509.350816] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [509.350919] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [509.351022] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [509.351130] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [509.351234] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [509.351336] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [509.351441] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [509.351546] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [509.351648] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [509.351751] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [509.351853] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [509.351956] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [509.352057] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [509.352166] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [509.352270] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [509.352372] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [509.352474] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [509.352575] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [509.352677] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [509.352779] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [509.352881] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [509.352985] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [509.353093] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [509.353197] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset
<7> [509.353301] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:387:pipe C] releasing DPLL 0
<7> [509.353499] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xd -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [509.353590] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:149:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x4 -> 0x1
<7> [509.353669] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:387:pipe C] dbuf slices 0xc -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x4 -> 0x1
<7> [509.353750] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [509.353828] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:143:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [509.353903] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [509.353978] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [509.354050] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [509.354139] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [509.354214] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:381:cursor C] ddb (2003 - 2048) -> ( 0 - 0), size 45 -> 0
<7> [509.354313] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:149:pipe A] data rate 1390840 num active planes 1
<7> [509.354433] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [509.354547] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [509.354660] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [509.354774] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [509.354885] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [509.354997] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:149:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [509.355117] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:387:pipe C] min cdclk: 173855 kHz -> 0 kHz
<7> [509.355291] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:149:pipe A] allocated DPLL 0
<7> [509.355393] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:149:pipe A] reserving DPLL 0
<7> [509.355502] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:149:pipe A] enable: yes [modeset]
<7> [509.355620] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [509.355734] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [509.355845] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [509.355954] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [509.356065] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [509.356179] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [509.356290] 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> [509.356402] 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> [509.356511] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [509.356620] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [509.356727] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [509.356835] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0
<7> [509.356942] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [509.357050] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [509.357165] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [509.357275] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [509.357382] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [509.357489] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [509.357597] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [509.357705] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [509.357814] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [509.357923] 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> [509.358034] 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> [509.358150] 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> [509.358259] 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> [509.358366] 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> [509.358474] 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> [509.358581] 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> [509.358690] 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> [509.358800] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855
<7> [509.358909] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [509.359015] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [509.359125] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [509.359233] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [509.359339] 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> [509.359448] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [509.359556] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [509.359663] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [509.359769] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [509.359874] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [509.359980] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [509.360090] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [509.360199] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [509.360306] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [509.360413] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [509.360518] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [509.360624] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [509.360729] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [509.360834] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [509.360939] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [509.361044] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [509.361156] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [509.361266] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [509.361372] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [509.361478] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [509.361583] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [509.361688] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [509.361794] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:33:plane 1A] fb: [FB:392] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [509.361905] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [509.362012] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [509.362133] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:63:plane 2A] fb: [NOFB], visible: no
<7> [509.362241] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:93:plane 3A] fb: [NOFB], visible: no
<7> [509.362346] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:123:plane 4A] fb: [NOFB], visible: no
<7> [509.362451] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:133:plane 5A] fb: [NOFB], visible: no
<7> [509.362556] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:143:cursor A] fb: [NOFB], visible: no
<7> [509.362664] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:387:pipe C] enable: no [modeset]
<7> [509.362770] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:271:plane 1C] fb: [NOFB], visible: no
<7> [509.362877] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:301:plane 2C] fb: [NOFB], visible: no
<7> [509.362982] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:331:plane 3C] fb: [NOFB], visible: no
<7> [509.363093] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:361:plane 4C] fb: [NOFB], visible: no
<7> [509.363198] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:371:plane 5C] fb: [NOFB], visible: no
<7> [509.363302] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:381:cursor C] fb: [NOFB], visible: no
<7> [509.363524] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [509.363911] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [509.364035] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [509.567243] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 0
<7> [509.568059] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe C
<7> [509.578778] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turn panel power off
<7> [509.579144] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [509.579528] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [509.631549] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [509.631930] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - short
<7> [509.640128] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [509.640478] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x4, on? 1) for [CRTC:387:pipe C]
<7> [509.640506] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:390:DDI A/PHY A]
<7> [509.641778] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [509.642259] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [509.642738] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:390:DDI A/PHY A]
<7> [509.643066] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:399:DDI TC1/PHY TC1]
<7> [509.643409] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DP-MST A]
<7> [509.643724] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST B]
<7> [509.644034] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST C]
<7> [509.644360] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:411:DDI TC2/PHY TC2]
<7> [509.644665] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DP-MST A]
<7> [509.644951] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST B]
<7> [509.645222] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST C]
<7> [509.645506] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:419:DDI TC3/PHY TC3]
<7> [509.645778] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DP-MST A]
<7> [509.646049] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST B]
<7> [509.646338] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST C]
<7> [509.646665] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [509.647129] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [509.647415] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [509.647732] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [509.649249] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:149:pipe A]
<7> [509.649582] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [509.651675] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turn panel power on
<7> [509.651964] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power cycle (489 ms remaining)
<7> [509.669358] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [509.669809] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - long
<7> [509.670298] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [509.670824] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:390:DDI A/PHY A]
<7> [510.143958] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [510.155309] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [510.156066] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power on
<7> [510.156704] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [510.192309] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [510.192618] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - long
<7> [510.192884] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [510.193227] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:390:DDI A/PHY A]
<7> [510.369679] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [510.370093] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turning VDD on
<7> [510.370436] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [510.372690] 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> [510.374017] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [510.374829] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [510.376032] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [510.377219] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [510.378407] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Clock recovery OK
<7> [510.378793] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [510.380330] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [510.380716] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [510.381529] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [510.382085] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [510.382465] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [510.382950] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 4518
<7> [510.398888] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [510.401339] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:391:eDP-1]
<7> [510.401840] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A]
<7> [510.404569] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_C
<7> [510.405455] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [510.405994] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:387:pipe C]
<7> [510.407274] xe 0000:00:02.0: [drm:drm_client_dev_restore] fbdev: ret=0
<6> [510.409172] [IGT] kms_flip: exiting, ret=98
<7> [510.424657] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [510.424830] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [510.424958] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
Created at 2026-01-21 22:00:20