Results for igt@kms_flip@flip-vs-expired-vblank-interruptible@b-edp1

Result: Fail

i915_display_info10 igt_runner10 results10.json results10-xe-load.json guc_logs10.tar i915_display_info_post_exec10 serial_data10 boot10 dmesg10

DetailValue
Duration 11.07 seconds
Hostname 
shard-lnl-5
Igt-Version 
IGT-Version: 2.4-gb0612a4a1 (x86_64) (Linux: 7.1.0-rc5-lgci-xe-xe-pw-167572v1-debug+ x86_64)
Out 
Starting dynamic subtest: B-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Stack trace:
  #0 ../lib/igt_core.c:2106 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest B-eDP1: FAIL (11.073s)
Err 
Starting dynamic subtest: B-eDP1
[92.018234] (kms_flip:2887) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[92.018323] (kms_flip:2887) CRITICAL: Failed assertion: end - start < 500
[92.018365] (kms_flip:2887) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-eDP1 failed.
**** DEBUG ****
[90.001184] (kms_flip:2887) DEBUG: Vblank took 56us
[90.017780] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.806396
last_received_ts = 91.805717
last_seq = 470
current_ts = 91.823067
current_received_ts = 91.822372
current_seq = 471
count = 466
seq_step = 1
[90.017835] (kms_flip:2887) DEBUG: Vblank took 52us
[90.034438] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.823067
last_received_ts = 91.822372
last_seq = 471
current_ts = 91.839737
current_received_ts = 91.839043
current_seq = 472
count = 467
seq_step = 1
[90.034494] (kms_flip:2887) DEBUG: Vblank took 53us
[90.051152] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.839737
last_received_ts = 91.839043
last_seq = 472
current_ts = 91.856407
current_received_ts = 91.855759
current_seq = 473
count = 468
seq_step = 1
[90.051211] (kms_flip:2887) DEBUG: Vblank took 55us
[90.067660] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.856407
last_received_ts = 91.855759
last_seq = 473
current_ts = 91.873085
current_received_ts = 91.872276
current_seq = 474
count = 469
seq_step = 1
[90.067697] (kms_flip:2887) DEBUG: Vblank took 34us
[90.084426] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.873085
last_received_ts = 91.872276
last_seq = 474
current_ts = 91.889755
current_received_ts = 91.888992
current_seq = 475
count = 470
seq_step = 1
[90.084575] (kms_flip:2887) DEBUG: Vblank took 127us
[90.101048] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.889755
last_received_ts = 91.888992
last_seq = 475
current_ts = 91.906425
current_received_ts = 91.905655
current_seq = 476
count = 471
seq_step = 1
[90.101133] (kms_flip:2887) DEBUG: Vblank took 68us
[90.117731] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.906425
last_received_ts = 91.905655
last_seq = 476
current_ts = 91.923088
current_received_ts = 91.922333
current_seq = 477
count = 472
seq_step = 1
[90.117872] (kms_flip:2887) DEBUG: Vblank took 115us
[90.134534] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.923088
last_received_ts = 91.922333
last_seq = 477
current_ts = 91.939766
current_received_ts = 91.939148
current_seq = 478
count = 473
seq_step = 1
[90.134625] (kms_flip:2887) DEBUG: Vblank took 71us
[90.151254] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.939766
last_received_ts = 91.939148
last_seq = 478
current_ts = 91.956436
current_received_ts = 91.955894
current_seq = 479
count = 474
seq_step = 1
[90.151335] (kms_flip:2887) DEBUG: Vblank took 65us
[90.167730] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.956436
last_received_ts = 91.955894
last_seq = 479
current_ts = 91.973106
current_received_ts = 91.972382
current_seq = 480
count = 475
seq_step = 1
[90.167800] (kms_flip:2887) DEBUG: Vblank took 59us
[90.184405] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.973106
last_received_ts = 91.972382
last_seq = 480
current_ts = 91.989777
current_received_ts = 91.989059
current_seq = 481
count = 476
seq_step = 1
[90.184489] (kms_flip:2887) DEBUG: Vblank took 77us
[90.201142] (kms_flip:2887) DEBUG: name = flip
last_ts = 91.989777
last_received_ts = 91.989059
last_seq = 481
current_ts = 92.006447
current_received_ts = 92.005806
current_seq = 482
count = 477
seq_step = 1
[90.201227] (kms_flip:2887) DEBUG: Vblank took 76us
[90.217719] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.006447
last_received_ts = 92.005806
last_seq = 482
current_ts = 92.023117
current_received_ts = 92.022392
current_seq = 483
count = 478
seq_step = 1
[90.217799] (kms_flip:2887) DEBUG: Vblank took 73us
[90.234513] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.023117
last_received_ts = 92.022392
last_seq = 483
current_ts = 92.039787
current_received_ts = 92.039192
current_seq = 484
count = 479
seq_step = 1
[90.234591] (kms_flip:2887) DEBUG: Vblank took 72us
[90.251144] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.039787
last_received_ts = 92.039192
last_seq = 484
current_ts = 92.056465
current_received_ts = 92.055832
current_seq = 485
count = 480
seq_step = 1
[90.251223] (kms_flip:2887) DEBUG: Vblank took 73us
[90.267851] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.056465
last_received_ts = 92.055832
last_seq = 485
current_ts = 92.073128
current_received_ts = 92.072548
current_seq = 486
count = 481
seq_step = 1
[90.267927] (kms_flip:2887) DEBUG: Vblank took 71us
[90.284538] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.073128
last_received_ts = 92.072548
last_seq = 486
current_ts = 92.089806
current_received_ts = 92.089241
current_seq = 487
count = 482
seq_step = 1
[90.284616] (kms_flip:2887) DEBUG: Vblank took 72us
[90.301195] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.089806
last_received_ts = 92.089241
last_seq = 487
current_ts = 92.106468
current_received_ts = 92.105911
current_seq = 488
count = 483
seq_step = 1
[90.301268] (kms_flip:2887) DEBUG: Vblank took 68us
[90.317801] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.106468
last_received_ts = 92.105911
last_seq = 488
current_ts = 92.123146
current_received_ts = 92.122520
current_seq = 489
count = 484
seq_step = 1
[90.317877] (kms_flip:2887) DEBUG: Vblank took 70us
[90.334454] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.123146
last_received_ts = 92.122520
last_seq = 489
current_ts = 92.139816
current_received_ts = 92.139183
current_seq = 490
count = 485
seq_step = 1
[90.334501] (kms_flip:2887) DEBUG: Vblank took 42us
[90.351175] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.139816
last_received_ts = 92.139183
last_seq = 490
current_ts = 92.156494
current_received_ts = 92.155907
current_seq = 491
count = 486
seq_step = 1
[90.351248] (kms_flip:2887) DEBUG: Vblank took 67us
[90.367831] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.156494
last_received_ts = 92.155907
last_seq = 491
current_ts = 92.173157
current_received_ts = 92.172569
current_seq = 492
count = 487
seq_step = 1
[90.367902] (kms_flip:2887) DEBUG: Vblank took 65us
[90.384495] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.173157
last_received_ts = 92.172569
last_seq = 492
current_ts = 92.189827
current_received_ts = 92.189247
current_seq = 493
count = 488
seq_step = 1
[90.384568] (kms_flip:2887) DEBUG: Vblank took 67us
[90.401170] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.189827
last_received_ts = 92.189247
last_seq = 493
current_ts = 92.206505
current_received_ts = 92.205925
current_seq = 494
count = 489
seq_step = 1
[90.401254] (kms_flip:2887) DEBUG: Vblank took 78us
[90.417831] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.206505
last_received_ts = 92.205925
last_seq = 494
current_ts = 92.223167
current_received_ts = 92.222595
current_seq = 495
count = 490
seq_step = 1
[90.417881] (kms_flip:2887) DEBUG: Vblank took 44us
[90.434339] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.223167
last_received_ts = 92.222595
last_seq = 495
current_ts = 92.239845
current_received_ts = 92.239105
current_seq = 496
count = 491
seq_step = 1
[90.434407] (kms_flip:2887) DEBUG: Vblank took 63us
[90.451156] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.239845
last_received_ts = 92.239105
last_seq = 496
current_ts = 92.256508
current_received_ts = 92.255936
current_seq = 497
count = 492
seq_step = 1
[90.451206] (kms_flip:2887) DEBUG: Vblank took 45us
[90.467777] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.256508
last_received_ts = 92.255936
last_seq = 497
current_ts = 92.273193
current_received_ts = 92.272552
current_seq = 498
count = 493
seq_step = 1
[90.467888] (kms_flip:2887) DEBUG: Vblank took 101us
[90.484497] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.273193
last_received_ts = 92.272552
last_seq = 498
current_ts = 92.289856
current_received_ts = 92.289284
current_seq = 499
count = 494
seq_step = 1
[90.484576] (kms_flip:2887) DEBUG: Vblank took 72us
[90.501164] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.289856
last_received_ts = 92.289284
last_seq = 499
current_ts = 92.306526
current_received_ts = 92.305962
current_seq = 500
count = 495
seq_step = 1
[90.501260] (kms_flip:2887) DEBUG: Vblank took 88us
[90.517782] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.306526
last_received_ts = 92.305962
last_seq = 500
current_ts = 92.323204
current_received_ts = 92.322586
current_seq = 501
count = 496
seq_step = 1
[90.517863] (kms_flip:2887) DEBUG: Vblank took 73us
[90.534301] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.323204
last_received_ts = 92.322586
last_seq = 501
current_ts = 92.339874
current_received_ts = 92.339111
current_seq = 502
count = 497
seq_step = 1
[90.534375] (kms_flip:2887) DEBUG: Vblank took 68us
[90.551042] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.339874
last_received_ts = 92.339111
last_seq = 502
current_ts = 92.356544
current_received_ts = 92.355858
current_seq = 503
count = 498
seq_step = 1
[90.551110] (kms_flip:2887) DEBUG: Vblank took 61us
[90.567736] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.356544
last_received_ts = 92.355858
last_seq = 503
current_ts = 92.373215
current_received_ts = 92.372566
current_seq = 504
count = 499
seq_step = 1
[90.567802] (kms_flip:2887) DEBUG: Vblank took 61us
[90.584411] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.373215
last_received_ts = 92.372566
last_seq = 504
current_ts = 92.389885
current_received_ts = 92.389244
current_seq = 505
count = 500
seq_step = 1
[90.584459] (kms_flip:2887) DEBUG: Vblank took 43us
[90.601178] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.389885
last_received_ts = 92.389244
last_seq = 505
current_ts = 92.406555
current_received_ts = 92.406013
current_seq = 506
count = 501
seq_step = 1
[90.601222] (kms_flip:2887) DEBUG: Vblank took 39us
[90.617733] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.406555
last_received_ts = 92.406013
last_seq = 506
current_ts = 92.423233
current_received_ts = 92.422585
current_seq = 507
count = 502
seq_step = 1
[90.617811] (kms_flip:2887) DEBUG: Vblank took 72us
[90.634444] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.423233
last_received_ts = 92.422585
last_seq = 507
current_ts = 92.439896
current_received_ts = 92.439301
current_seq = 508
count = 503
seq_step = 1
[90.634525] (kms_flip:2887) DEBUG: Vblank took 74us
[90.650968] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.439896
last_received_ts = 92.439301
last_seq = 508
current_ts = 92.456573
current_received_ts = 92.455826
current_seq = 509
count = 504
seq_step = 1
[90.651040] (kms_flip:2887) DEBUG: Vblank took 65us
[90.667732] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.456573
last_received_ts = 92.455826
last_seq = 509
current_ts = 92.473236
current_received_ts = 92.472603
current_seq = 510
count = 505
seq_step = 1
[90.667802] (kms_flip:2887) DEBUG: Vblank took 64us
[90.684442] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.473236
last_received_ts = 92.472603
last_seq = 510
current_ts = 92.489906
current_received_ts = 92.489319
current_seq = 511
count = 506
seq_step = 1
[90.684521] (kms_flip:2887) DEBUG: Vblank took 73us
[90.701092] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.489906
last_received_ts = 92.489319
last_seq = 511
current_ts = 92.506584
current_received_ts = 92.505974
current_seq = 512
count = 507
seq_step = 1
[90.701149] (kms_flip:2887) DEBUG: Vblank took 52us
[90.717691] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.506584
last_received_ts = 92.505974
last_seq = 512
current_ts = 92.523254
current_received_ts = 92.522583
current_seq = 513
count = 508
seq_step = 1
[90.717784] (kms_flip:2887) DEBUG: Vblank took 86us
[90.734373] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.523254
last_received_ts = 92.522583
last_seq = 513
current_ts = 92.539925
current_received_ts = 92.539268
current_seq = 514
count = 509
seq_step = 1
[90.734447] (kms_flip:2887) DEBUG: Vblank took 68us
[90.751134] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.539925
last_received_ts = 92.539268
last_seq = 514
current_ts = 92.556595
current_received_ts = 92.556038
current_seq = 515
count = 510
seq_step = 1
[90.751179] (kms_flip:2887) DEBUG: Vblank took 39us
[90.767717] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.556595
last_received_ts = 92.556038
last_seq = 515
current_ts = 92.573265
current_received_ts = 92.572632
current_seq = 516
count = 511
seq_step = 1
[90.767798] (kms_flip:2887) DEBUG: Vblank took 76us
[90.784332] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.573265
last_received_ts = 92.572632
last_seq = 516
current_ts = 92.589935
current_received_ts = 92.589249
current_seq = 517
count = 512
seq_step = 1
[90.784403] (kms_flip:2887) DEBUG: Vblank took 66us
[90.801034] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.589935
last_received_ts = 92.589249
last_seq = 517
current_ts = 92.606606
current_received_ts = 92.605957
current_seq = 518
count = 513
seq_step = 1
[90.801140] (kms_flip:2887) DEBUG: Vblank took 98us
[90.817649] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.606606
last_received_ts = 92.605957
last_seq = 518
current_ts = 92.623283
current_received_ts = 92.622581
current_seq = 519
count = 514
seq_step = 1
[90.817721] (kms_flip:2887) DEBUG: Vblank took 66us
[90.834353] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.623283
last_received_ts = 92.622581
last_seq = 519
current_ts = 92.639946
current_received_ts = 92.639290
current_seq = 520
count = 515
seq_step = 1
[90.834427] (kms_flip:2887) DEBUG: Vblank took 68us
[90.851109] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.639946
last_received_ts = 92.639290
last_seq = 520
current_ts = 92.656616
current_received_ts = 92.656052
current_seq = 521
count = 516
seq_step = 1
[90.851186] (kms_flip:2887) DEBUG: Vblank took 72us
[90.867681] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.656616
last_received_ts = 92.656052
last_seq = 521
current_ts = 92.673294
current_received_ts = 92.672630
current_seq = 522
count = 517
seq_step = 1
[90.867755] (kms_flip:2887) DEBUG: Vblank took 67us
[90.884423] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.673294
last_received_ts = 92.672630
last_seq = 522
current_ts = 92.689964
current_received_ts = 92.689384
current_seq = 523
count = 518
seq_step = 1
[90.884494] (kms_flip:2887) DEBUG: Vblank took 66us
[90.901018] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.689964
last_received_ts = 92.689384
last_seq = 523
current_ts = 92.706635
current_received_ts = 92.705986
current_seq = 524
count = 519
seq_step = 1
[90.901120] (kms_flip:2887) DEBUG: Vblank took 71us
[90.917792] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.706635
last_received_ts = 92.705986
last_seq = 524
current_ts = 92.723312
current_received_ts = 92.722763
current_seq = 525
count = 520
seq_step = 1
[90.917868] (kms_flip:2887) DEBUG: Vblank took 70us
[90.934406] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.723312
last_received_ts = 92.722763
last_seq = 525
current_ts = 92.739975
current_received_ts = 92.739388
current_seq = 526
count = 521
seq_step = 1
[90.934481] (kms_flip:2887) DEBUG: Vblank took 69us
[90.951026] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.739975
last_received_ts = 92.739388
last_seq = 526
current_ts = 92.756645
current_received_ts = 92.756012
current_seq = 527
count = 522
seq_step = 1
[90.951072] (kms_flip:2887) DEBUG: Vblank took 39us
[90.967683] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.756645
last_received_ts = 92.756012
last_seq = 527
current_ts = 92.773315
current_received_ts = 92.772675
current_seq = 528
count = 523
seq_step = 1
[90.967733] (kms_flip:2887) DEBUG: Vblank took 44us
[90.984408] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.773315
last_received_ts = 92.772675
last_seq = 528
current_ts = 92.789986
current_received_ts = 92.789406
current_seq = 529
count = 524
seq_step = 1
[90.984486] (kms_flip:2887) DEBUG: Vblank took 73us
[91.001067] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.789986
last_received_ts = 92.789406
last_seq = 529
current_ts = 92.806656
current_received_ts = 92.806076
current_seq = 530
count = 525
seq_step = 1
[91.001169] (kms_flip:2887) DEBUG: Vblank took 94us
[91.017687] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.806656
last_received_ts = 92.806076
last_seq = 530
current_ts = 92.823334
current_received_ts = 92.822701
current_seq = 531
count = 526
seq_step = 1
[91.017760] (kms_flip:2887) DEBUG: Vblank took 68us
[91.034419] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.823334
last_received_ts = 92.822701
last_seq = 531
current_ts = 92.840004
current_received_ts = 92.839439
current_seq = 532
count = 527
seq_step = 1
[91.034499] (kms_flip:2887) DEBUG: Vblank took 74us
[91.051061] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.840004
last_received_ts = 92.839439
last_seq = 532
current_ts = 92.856667
current_received_ts = 92.856087
current_seq = 533
count = 528
seq_step = 1
[91.051139] (kms_flip:2887) DEBUG: Vblank took 73us
[91.067684] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.856667
last_received_ts = 92.856087
last_seq = 533
current_ts = 92.873337
current_received_ts = 92.872719
current_seq = 534
count = 529
seq_step = 1
[91.067762] (kms_flip:2887) DEBUG: Vblank took 73us
[91.084390] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.873337
last_received_ts = 92.872719
last_seq = 534
current_ts = 92.890015
current_received_ts = 92.889435
current_seq = 535
count = 530
seq_step = 1
[91.084467] (kms_flip:2887) DEBUG: Vblank took 72us
[91.100941] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.890015
last_received_ts = 92.889435
last_seq = 535
current_ts = 92.906685
current_received_ts = 92.905991
current_seq = 536
count = 531
seq_step = 1
[91.101038] (kms_flip:2887) DEBUG: Vblank took 75us
[91.117649] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.906685
last_received_ts = 92.905991
last_seq = 536
current_ts = 92.923347
current_received_ts = 92.922707
current_seq = 537
count = 532
seq_step = 1
[91.117727] (kms_flip:2887) DEBUG: Vblank took 72us
[91.134329] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.923347
last_received_ts = 92.922707
last_seq = 537
current_ts = 92.940025
current_received_ts = 92.939392
current_seq = 538
count = 533
seq_step = 1
[91.134408] (kms_flip:2887) DEBUG: Vblank took 73us
[91.151081] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.940025
last_received_ts = 92.939392
last_seq = 538
current_ts = 92.956696
current_received_ts = 92.956146
current_seq = 539
count = 534
seq_step = 1
[91.151130] (kms_flip:2887) DEBUG: Vblank took 43us
[91.167689] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.956696
last_received_ts = 92.956146
last_seq = 539
current_ts = 92.973366
current_received_ts = 92.972763
current_seq = 540
count = 535
seq_step = 1
[91.167744] (kms_flip:2887) DEBUG: Vblank took 49us
[91.184288] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.973366
last_received_ts = 92.972763
last_seq = 540
current_ts = 92.990036
current_received_ts = 92.989372
current_seq = 541
count = 536
seq_step = 1
[91.184360] (kms_flip:2887) DEBUG: Vblank took 67us
[91.200964] (kms_flip:2887) DEBUG: name = flip
last_ts = 92.990036
last_received_ts = 92.989372
last_seq = 541
current_ts = 93.006706
current_received_ts = 93.006050
current_seq = 542
count = 537
seq_step = 1
[91.201033] (kms_flip:2887) DEBUG: Vblank took 64us
[91.217624] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.006706
last_received_ts = 93.006050
last_seq = 542
current_ts = 93.023384
current_received_ts = 93.022720
current_seq = 543
count = 538
seq_step = 1
[91.217700] (kms_flip:2887) DEBUG: Vblank took 71us
[91.234419] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.023384
last_received_ts = 93.022720
last_seq = 543
current_ts = 93.040047
current_received_ts = 93.039520
current_seq = 544
count = 539
seq_step = 1
[91.234466] (kms_flip:2887) DEBUG: Vblank took 40us
[91.251037] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.040047
last_received_ts = 93.039520
last_seq = 544
current_ts = 93.056725
current_received_ts = 93.056145
current_seq = 545
count = 540
seq_step = 1
[91.251136] (kms_flip:2887) DEBUG: Vblank took 93us
[91.267526] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.056725
last_received_ts = 93.056145
last_seq = 545
current_ts = 93.073395
current_received_ts = 93.072639
current_seq = 546
count = 541
seq_step = 1
[91.267598] (kms_flip:2887) DEBUG: Vblank took 66us
[91.284376] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.073395
last_received_ts = 93.072639
last_seq = 546
current_ts = 93.090065
current_received_ts = 93.089493
current_seq = 547
count = 542
seq_step = 1
[91.284431] (kms_flip:2887) DEBUG: Vblank took 49us
[91.301012] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.090065
last_received_ts = 93.089493
last_seq = 547
current_ts = 93.106735
current_received_ts = 93.106140
current_seq = 548
count = 543
seq_step = 1
[91.301090] (kms_flip:2887) DEBUG: Vblank took 71us
[91.317522] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.106735
last_received_ts = 93.106140
last_seq = 548
current_ts = 93.123405
current_received_ts = 93.122658
current_seq = 549
count = 544
seq_step = 1
[91.317593] (kms_flip:2887) DEBUG: Vblank took 66us
[91.334375] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.123405
last_received_ts = 93.122658
last_seq = 549
current_ts = 93.140068
current_received_ts = 93.139519
current_seq = 550
count = 545
seq_step = 1
[91.334425] (kms_flip:2887) DEBUG: Vblank took 44us
[91.350921] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.140068
last_received_ts = 93.139519
last_seq = 550
current_ts = 93.156746
current_received_ts = 93.156067
current_seq = 551
count = 546
seq_step = 1
[91.350975] (kms_flip:2887) DEBUG: Vblank took 48us
[91.367657] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.156746
last_received_ts = 93.156067
last_seq = 551
current_ts = 93.173416
current_received_ts = 93.172813
current_seq = 552
count = 547
seq_step = 1
[91.367735] (kms_flip:2887) DEBUG: Vblank took 72us
[91.384283] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.173416
last_received_ts = 93.172813
last_seq = 552
current_ts = 93.190079
current_received_ts = 93.189445
current_seq = 553
count = 548
seq_step = 1
[91.384361] (kms_flip:2887) DEBUG: Vblank took 73us
[91.401022] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.190079
last_received_ts = 93.189445
last_seq = 553
current_ts = 93.206757
current_received_ts = 93.206192
current_seq = 554
count = 549
seq_step = 1
[91.401099] (kms_flip:2887) DEBUG: Vblank took 71us
[91.417537] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.206757
last_received_ts = 93.206192
last_seq = 554
current_ts = 93.223427
current_received_ts = 93.222710
current_seq = 555
count = 550
seq_step = 1
[91.417615] (kms_flip:2887) DEBUG: Vblank took 72us
[91.434342] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.223427
last_received_ts = 93.222710
last_seq = 555
current_ts = 93.240105
current_received_ts = 93.239525
current_seq = 556
count = 551
seq_step = 1
[91.434420] (kms_flip:2887) DEBUG: Vblank took 72us
[91.450924] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.240105
last_received_ts = 93.239525
last_seq = 556
current_ts = 93.256767
current_received_ts = 93.256111
current_seq = 557
count = 552
seq_step = 1
[91.451002] (kms_flip:2887) DEBUG: Vblank took 73us
[91.467568] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.256767
last_received_ts = 93.256111
last_seq = 557
current_ts = 93.273445
current_received_ts = 93.272766
current_seq = 558
count = 553
seq_step = 1
[91.467623] (kms_flip:2887) DEBUG: Vblank took 49us
[91.484323] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.273445
last_received_ts = 93.272766
last_seq = 558
current_ts = 93.290108
current_received_ts = 93.289528
current_seq = 559
count = 554
seq_step = 1
[91.484401] (kms_flip:2887) DEBUG: Vblank took 71us
[91.500988] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.290108
last_received_ts = 93.289528
last_seq = 559
current_ts = 93.306786
current_received_ts = 93.306198
current_seq = 560
count = 555
seq_step = 1
[91.501068] (kms_flip:2887) DEBUG: Vblank took 73us
[91.517650] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.306786
last_received_ts = 93.306198
last_seq = 560
current_ts = 93.323456
current_received_ts = 93.322868
current_seq = 561
count = 556
seq_step = 1
[91.517724] (kms_flip:2887) DEBUG: Vblank took 67us
[91.534343] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.323456
last_received_ts = 93.322868
last_seq = 561
current_ts = 93.340118
current_received_ts = 93.339561
current_seq = 562
count = 557
seq_step = 1
[91.534399] (kms_flip:2887) DEBUG: Vblank took 49us
[91.550981] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.340118
last_received_ts = 93.339561
last_seq = 562
current_ts = 93.356789
current_received_ts = 93.356209
current_seq = 563
count = 558
seq_step = 1
[91.551058] (kms_flip:2887) DEBUG: Vblank took 70us
[91.567573] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.356789
last_received_ts = 93.356209
last_seq = 563
current_ts = 93.373466
current_received_ts = 93.372810
current_seq = 564
count = 559
seq_step = 1
[91.567647] (kms_flip:2887) DEBUG: Vblank took 69us
[91.584360] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.373466
last_received_ts = 93.372810
last_seq = 564
current_ts = 93.390129
current_received_ts = 93.389603
current_seq = 565
count = 560
seq_step = 1
[91.584436] (kms_flip:2887) DEBUG: Vblank took 68us
[91.600916] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.390129
last_received_ts = 93.389603
last_seq = 565
current_ts = 93.406807
current_received_ts = 93.406166
current_seq = 566
count = 561
seq_step = 1
[91.600997] (kms_flip:2887) DEBUG: Vblank took 75us
[91.617573] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.406807
last_received_ts = 93.406166
last_seq = 566
current_ts = 93.423477
current_received_ts = 93.422829
current_seq = 567
count = 562
seq_step = 1
[91.617646] (kms_flip:2887) DEBUG: Vblank took 67us
[91.634256] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.423477
last_received_ts = 93.422829
last_seq = 567
current_ts = 93.440147
current_received_ts = 93.439522
current_seq = 568
count = 563
seq_step = 1
[91.634331] (kms_flip:2887) DEBUG: Vblank took 70us
[91.650871] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.440147
last_received_ts = 93.439522
last_seq = 568
current_ts = 93.456818
current_received_ts = 93.456139
current_seq = 569
count = 564
seq_step = 1
[91.650950] (kms_flip:2887) DEBUG: Vblank took 72us
[91.667620] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.456818
last_received_ts = 93.456139
last_seq = 569
current_ts = 93.473495
current_received_ts = 93.472893
current_seq = 570
count = 565
seq_step = 1
[91.667697] (kms_flip:2887) DEBUG: Vblank took 70us
[91.684140] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.473495
last_received_ts = 93.472893
last_seq = 570
current_ts = 93.490158
current_received_ts = 93.489426
current_seq = 571
count = 566
seq_step = 1
[91.684207] (kms_flip:2887) DEBUG: Vblank took 61us
[91.700971] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.490158
last_received_ts = 93.489426
last_seq = 571
current_ts = 93.506828
current_received_ts = 93.506264
current_seq = 572
count = 567
seq_step = 1
[91.701050] (kms_flip:2887) DEBUG: Vblank took 72us
[91.717568] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.506828
last_received_ts = 93.506264
last_seq = 572
current_ts = 93.523499
current_received_ts = 93.522865
current_seq = 573
count = 568
seq_step = 1
[91.717646] (kms_flip:2887) DEBUG: Vblank took 71us
[91.734342] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.523499
last_received_ts = 93.522865
last_seq = 573
current_ts = 93.540169
current_received_ts = 93.539642
current_seq = 574
count = 569
seq_step = 1
[91.734393] (kms_flip:2887) DEBUG: Vblank took 45us
[91.750794] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.540169
last_received_ts = 93.539642
last_seq = 574
current_ts = 93.556847
current_received_ts = 93.556107
current_seq = 575
count = 570
seq_step = 1
[91.750866] (kms_flip:2887) DEBUG: Vblank took 66us
[91.767541] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.556847
last_received_ts = 93.556107
last_seq = 575
current_ts = 93.573517
current_received_ts = 93.572861
current_seq = 576
count = 571
seq_step = 1
[91.767619] (kms_flip:2887) DEBUG: Vblank took 71us
[91.784193] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.573517
last_received_ts = 93.572861
last_seq = 576
current_ts = 93.590187
current_received_ts = 93.589516
current_seq = 577
count = 572
seq_step = 1
[91.784287] (kms_flip:2887) DEBUG: Vblank took 87us
[91.800968] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.590187
last_received_ts = 93.589516
last_seq = 577
current_ts = 93.606857
current_received_ts = 93.606300
current_seq = 578
count = 573
seq_step = 1
[91.801035] (kms_flip:2887) DEBUG: Vblank took 61us
[91.817466] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.606857
last_received_ts = 93.606300
last_seq = 578
current_ts = 93.623520
current_received_ts = 93.622803
current_seq = 579
count = 574
seq_step = 1
[91.817539] (kms_flip:2887) DEBUG: Vblank took 67us
[91.834291] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.623520
last_received_ts = 93.622803
last_seq = 579
current_ts = 93.640198
current_received_ts = 93.639633
current_seq = 580
count = 575
seq_step = 1
[91.834371] (kms_flip:2887) DEBUG: Vblank took 72us
[91.850955] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.640198
last_received_ts = 93.639633
last_seq = 580
current_ts = 93.656868
current_received_ts = 93.656303
current_seq = 581
count = 576
seq_step = 1
[91.851033] (kms_flip:2887) DEBUG: Vblank took 72us
[91.867462] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.656868
last_received_ts = 93.656303
last_seq = 581
current_ts = 93.673538
current_received_ts = 93.672813
current_seq = 582
count = 577
seq_step = 1
[91.867552] (kms_flip:2887) DEBUG: Vblank took 77us
[91.884304] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.673538
last_received_ts = 93.672813
last_seq = 582
current_ts = 93.690208
current_received_ts = 93.689667
current_seq = 583
count = 578
seq_step = 1
[91.884390] (kms_flip:2887) DEBUG: Vblank took 78us
[91.900864] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.690208
last_received_ts = 93.689667
last_seq = 583
current_ts = 93.706879
current_received_ts = 93.706230
current_seq = 584
count = 579
seq_step = 1
[91.900954] (kms_flip:2887) DEBUG: Vblank took 79us
[91.917607] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.706879
last_received_ts = 93.706230
last_seq = 584
current_ts = 93.723549
current_received_ts = 93.722984
current_seq = 585
count = 580
seq_step = 1
[91.917706] (kms_flip:2887) DEBUG: Vblank took 92us
[91.934079] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.723549
last_received_ts = 93.722984
last_seq = 585
current_ts = 93.740219
current_received_ts = 93.739464
current_seq = 586
count = 581
seq_step = 1
[91.934150] (kms_flip:2887) DEBUG: Vblank took 65us
[91.950911] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.740219
last_received_ts = 93.739464
last_seq = 586
current_ts = 93.756889
current_received_ts = 93.756302
current_seq = 587
count = 582
seq_step = 1
[91.950988] (kms_flip:2887) DEBUG: Vblank took 71us
[91.967581] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.756889
last_received_ts = 93.756302
last_seq = 587
current_ts = 93.773560
current_received_ts = 93.772980
current_seq = 588
count = 583
seq_step = 1
[91.967677] (kms_flip:2887) DEBUG: Vblank took 91us
[91.984285] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.773560
last_received_ts = 93.772980
last_seq = 588
current_ts = 93.790230
current_received_ts = 93.789688
current_seq = 589
count = 584
seq_step = 1
[91.984364] (kms_flip:2887) DEBUG: Vblank took 73us
[92.000856] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.790230
last_received_ts = 93.789688
last_seq = 589
current_ts = 93.806900
current_received_ts = 93.806267
current_seq = 590
count = 585
seq_step = 1
[92.000933] (kms_flip:2887) DEBUG: Vblank took 70us
[92.017521] (kms_flip:2887) DEBUG: name = flip
last_ts = 93.806900
last_received_ts = 93.806267
last_seq = 590
current_ts = 93.823570
current_received_ts = 93.822922
current_seq = 591
count = 586
seq_step = 1
[92.018224] (kms_flip:2887) DEBUG: Vblank took 689us
[92.018234] (kms_flip:2887) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[92.018323] (kms_flip:2887) CRITICAL: Failed assertion: end - start < 500
[92.018365] (kms_flip:2887) CRITICAL: Last errno: 4, Interrupted system call
[92.022486] (kms_flip:2887) igt_core-INFO: Stack trace:
[92.026703] (kms_flip:2887) igt_core-INFO:   #0 ../lib/igt_core.c:2106 __igt_fail_assert()
[92.028736] (kms_flip:2887) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
[92.028798] (kms_flip:2887) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
[92.028842] (kms_flip:2887) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
[92.028903] (kms_flip:2887) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
[92.033703] (kms_flip:2887) igt_core-INFO:   #5 [__libc_init_first+0x8a]
[92.035188] (kms_flip:2887) igt_core-INFO:   #6 [__libc_start_main+0x8b]
[92.035529] (kms_flip:2887) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-eDP1: FAIL (11.073s)
Dmesg
<6> [82.728347] [IGT] kms_flip: starting dynamic subtest B-eDP1
<7> [82.729076] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:433]
<7> [82.731558] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:434]
<7> [82.787208] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [82.787283] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [82.787405] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [82.787505] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [82.787602] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [82.787697] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0)
<7> [82.787806] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [82.787905] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [82.788012] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [82.788108] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [82.788193] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [82.788278] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [82.788364] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [82.788449] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [82.788535] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [82.788622] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [82.788707] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [82.788796] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [82.788887] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [82.788976] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [82.789064] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [82.789146] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [82.789229] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [82.789308] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [82.789388] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [82.789466] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [82.789545] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [82.789622] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [82.789700] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [82.789790] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [82.789889] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [82.789990] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [82.790088] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [82.790164] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [82.790240] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [82.790316] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [82.790392] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [82.790467] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [82.790542] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [82.790618] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [82.790699] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0
<7> [82.790846] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [82.790943] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [82.791065] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0
<7> [82.791139] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0
<7> [82.791198] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [82.791256] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [82.791314] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [82.791371] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] 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> [82.791445] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0
<7> [82.791532] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 34060 required 0 qgv_peak_bw: 38400
<7> [82.791616] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [82.791699] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [82.791891] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [82.792008] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [82.792118] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz
<7> [82.792227] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz
<7> [82.792312] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [82.792396] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [82.792478] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [82.792585] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]
<7> [82.792677] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [82.792761] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [82.792876] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [82.792989] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [82.793097] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [82.793186] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [82.793332] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [82.793424] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [82.793557] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2
<7> [82.805395] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [82.805580] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [83.011869] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [83.012573] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [83.022056] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [83.022475] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [83.022473] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [83.022932] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [83.022998] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [83.074010] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [83.074396] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]
<7> [83.074437] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [83.074932] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [83.075329] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [83.075746] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [83.075888] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [83.076379] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [83.076932] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [83.077334] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [83.077694] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [83.078065] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [83.078426] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [83.078837] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [83.079156] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [83.079467] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [83.079798] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [83.080126] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [83.080453] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [83.080792] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [83.081090] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [83.081386] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [83.081868] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [83.082176] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [83.082483] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [83.083080] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [83.083515] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [83.084042] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [83.084365] 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> [83.084800] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [83.085067] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [83.085985] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [83.086301] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [83.086532] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [83.086591] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [83.086744] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [83.087045] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:270:pipe B] 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> [83.087303] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [83.087564] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [83.087839] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:270:pipe B]
<7> [83.088084] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.enable (expected no, found yes)
<7> [83.088316] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.active (expected no, found yes)
<7> [83.088534] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)
<7> [83.088818] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in lane_count (expected 0, found 4)
<7> [83.089029] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)
<7> [83.089239] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [83.089471] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [83.089675] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [83.089869] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [83.090050] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [83.090225] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [83.090389] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [83.090570] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [83.090744] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [83.090903] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [83.091055] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [83.091203] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [83.091346] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [83.091488] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [83.091633] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [83.091769] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [83.091904] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [83.092035] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [83.092163] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [83.092306] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [83.092451] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [83.092572] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [83.092727] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [83.092843] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [83.092957] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [83.093069] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [83.093180] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [83.093289] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [83.093396] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [83.093505] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in dpll_hw_state
<7> [83.093621] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [83.093732] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 0, ssc_enabled: no, use_c10: no, tbt_mode: no
<7> [83.093840] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state:
<7> [83.093944] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0x0000, tx[1] = 0x0000, tx[2] = 0x0000
<7> [83.094046] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0000, cmn[1] = 0x0000, cmn[2] = 0x0000, cmn[3] = 0x0000
<7> [83.094145] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[0] = 0x0000
<7> [83.094240] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[1] = 0x0000
<7> [83.094332] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[2] = 0x0000
<7> [83.094424] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[3] = 0x0000
<7> [83.094517] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[4] = 0x0000
<7> [83.094607] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[5] = 0x0000
<7> [83.094721] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[6] = 0x0000
<7> [83.094820] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[7] = 0x0000
<7> [83.094915] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[8] = 0x0000
<7> [83.095008] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[9] = 0x0000
<7> [83.095104] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0000
<7> [83.095201] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00
<7> [83.095283] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [83.095362] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no
<7> [83.095441] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] c10pll_hw_state: fracen: no,
<7> [83.095518] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] multiplier: 225, tx_clk_div: 1.
<7> [83.095596] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] c10pll_rawhw_state:
<7> [83.095748] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] tx: 0x10, cmn: 0x21
<7> [83.095851] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [83.095952] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [83.096037] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [83.096114] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [83.096191] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [83.096267] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [83.096342] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [83.096418] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [83.096492] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [83.096568] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] fastset requirement not met, forcing full modeset
<7> [83.096699] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [83.096784] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:270:pipe B] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x2
<7> [83.096889] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:154:plane 1B] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [83.096963] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:264:cursor B] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [83.097036] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [83.097098] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0
<7> [83.097153] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197
<7> [83.097207] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] 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> [83.097276] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:270:pipe B] data rate 1390840 num active planes 1
<7> [83.097362] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23529 required 1461 qgv_peak_bw: 38400
<7> [83.097447] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36259 required 1461 qgv_peak_bw: 38400
<7> [83.097531] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [83.097621] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [83.097728] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [83.097834] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:270:pipe B] min cdclk: 0 kHz -> 173855 kHz
<7> [83.097970] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz
<7> [83.098067] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [83.098148] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [83.098229] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [83.098321] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:270:pipe B] allocated DPLL 0
<7> [83.098400] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:270:pipe B] reserving DPLL 0
<7> [83.098481] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:270:pipe B] enable: yes [modeset]
<7> [83.098566] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [83.098668] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: B, pipe bpp: 30, dithering: 0
<7> [83.098779] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [83.098885] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [83.098978] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [83.099063] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [83.099143] 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> [83.099221] 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> [83.099299] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [83.099377] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [83.099454] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [83.099531] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [83.099607] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [83.099724] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [83.099833] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [83.099929] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [83.100012] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [83.100093] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [83.100169] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [83.100245] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [83.100320] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [83.100396] 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: 37 vsync start: 103, vsync end: 97
<7> [83.100471] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1869, vmax vblank: 1869, vmin vtotal: 1906, vmax vtotal: 1906
<7> [83.100546] 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> [83.100624] 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> [83.100719] 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> [83.100817] 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> [83.100914] 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> [83.101009] 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> [83.101089] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0
<7> [83.101169] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [83.101243] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [83.101316] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [83.101388] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [83.101463] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [83.101539] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [83.101622] 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> [83.101723] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [83.101823] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [83.101920] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [83.102002] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [83.102078] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [83.102154] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [83.102229] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [83.102304] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [83.102378] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [83.102454] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [83.102533] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [83.102618] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [83.102717] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [83.102813] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [83.102908] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [83.102988] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [83.103062] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [83.103136] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [83.103210] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [83.103284] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [83.103357] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [83.103430] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:154:plane 1B] fb: [FB:433] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [83.103505] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [83.103579] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [83.103683] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:184:plane 2B] fb: [NOFB], visible: no
<7> [83.103693] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [83.103781] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:214:plane 3B] fb: [NOFB], visible: no
<7> [83.103862] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [83.103879] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:244:plane 4B] fb: [NOFB], visible: no
<7> [83.103975] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:254:plane 5B] fb: [NOFB], visible: no
<7> [83.103993] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [83.104070] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:264:cursor B] fb: [NOFB], visible: no
<7> [83.104143] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling always-on
<7> [83.104387] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling always-on
<7> [83.104496] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [83.104740] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [83.104903] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [83.105044] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_B
<7> [83.105180] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x2 (CLKGATE_DIS_DSSDSC=0xa2000000)
<7> [83.105276] 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> [83.105370] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [83.105457] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [83.105542] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [83.105618] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [83.105708] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [83.105798] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [83.105886] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [83.105963] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [83.106031] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [83.106096] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [83.106160] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [83.106223] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [83.106286] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [83.106352] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [83.106420] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [83.106508] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [83.106670] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [83.106753] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [83.106878] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [83.107649] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x2, on? 0) for [CRTC:270:pipe B]
<7> [83.107754] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [83.109772] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [83.109872] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (465 ms remaining)
<7> [83.110974] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [83.111080] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [83.111170] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [83.111270] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [83.579635] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [83.681461] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [83.681836] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on
<7> [83.682166] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [83.718611] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [83.719202] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [83.719750] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [83.720300] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [83.894835] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [83.895394] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [83.895791] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [83.898074] 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> [83.899645] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [83.900506] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [83.901678] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [83.903117] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [83.904310] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK
<7> [83.904740] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [83.907152] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [83.907565] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [83.908422] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe B
<7> [83.908946] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [83.909357] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe B
<7> [83.909851] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 13892
<7> [83.942684] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [83.944344] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [83.944719] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:270:pipe B]
<7> [86.473595] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off
<7> [86.474168] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [93.759085] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [93.759422] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [93.759605] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<6> [93.802534] [IGT] kms_flip: finished subtest B-eDP1, FAIL
Created at 2026-05-30 00:05:23