Results for igt@kms_flip@plain-flip-ts-check@a-edp1

Result: Fail

integration-manifest git-log-oneline i915_display_info20 igt_runner20 runtimes20 results20.json results20-i915-load.json guc_logs20.tar i915_display_info_post_exec20 boot20 dmesg20

DetailValue
Duration 20.77 seconds
Hostname 
shard-mtlp-2
Igt-Version 
IGT-Version: 2.3-ga50285a68 (x86_64) (Linux: 7.0.0-rc2-CI_DRM_18076-g69ee18cb718c+ x86_64)
Out 
Using IGT_SRANDOM=1772526470 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: plain-flip-ts-check
Starting dynamic subtest: A-eDP1
  2880x1800: 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa 
Expected frametime: 11111us; measured 11581.8us +- 2.455us accuracy 0.06%
vblank interval differs from modeline! expected 11111.1us, measured 11582us +- 2.455us, difference 470.7us (191.7 sigma)
Event flip: expected 647, counted 657, passrate = 16.29%, encoder type 2
Expected frametime: 11111us; measured 11221.1us +- 6.592us accuracy 0.18%
vblank interval differs from modeline! expected 11111.1us, measured 11221us +- 6.592us, difference 110.0us (16.7 sigma)
Event flip: expected 668, counted 671, passrate = 70.19%, encoder type 2
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (20.767s)
Err 
Starting subtest: plain-flip-ts-check
Starting dynamic subtest: A-eDP1
(kms_flip:2918) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1707:
(kms_flip:2918) CRITICAL: Failed assertion: !retried
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:2918) DEBUG: flip ts/seq: last 531.083313/7450, current 531.094421/7451: elapsed=11161.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.083313/7450, current 531.094421/7451: elapsed=11161.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.094421
last_received_ts = 531.094055
last_seq = 7451
current_ts = 531.105591
current_received_ts = 531.105225
current_seq = 7452
count = 591
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.094421/7451, current 531.105591/7452: elapsed=11156.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.094421/7451, current 531.105591/7452: elapsed=11156.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.105591
last_received_ts = 531.105225
last_seq = 7452
current_ts = 531.116760
current_received_ts = 531.116394
current_seq = 7453
count = 592
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.105591/7452, current 531.116760/7453: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.105591/7452, current 531.116760/7453: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.116760
last_received_ts = 531.116394
last_seq = 7453
current_ts = 531.127930
current_received_ts = 531.127563
current_seq = 7454
count = 593
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.116760/7453, current 531.127930/7454: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.116760/7453, current 531.127930/7454: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.127930
last_received_ts = 531.127563
last_seq = 7454
current_ts = 531.139099
current_received_ts = 531.138672
current_seq = 7455
count = 594
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.127930/7454, current 531.139099/7455: elapsed=11161.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.127930/7454, current 531.139099/7455: elapsed=11161.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.139099
last_received_ts = 531.138672
last_seq = 7455
current_ts = 531.150208
current_received_ts = 531.149841
current_seq = 7456
count = 595
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.139099/7455, current 531.150208/7456: elapsed=11157.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.139099/7455, current 531.150208/7456: elapsed=11157.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.150208
last_received_ts = 531.149841
last_seq = 7456
current_ts = 531.161377
current_received_ts = 531.161011
current_seq = 7457
count = 596
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.150208/7456, current 531.161377/7457: elapsed=11160.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.150208/7456, current 531.161377/7457: elapsed=11160.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.161377
last_received_ts = 531.161011
last_seq = 7457
current_ts = 531.172546
current_received_ts = 531.172180
current_seq = 7458
count = 597
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.161377/7457, current 531.172546/7458: elapsed=11160.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.161377/7457, current 531.172546/7458: elapsed=11160.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.172546
last_received_ts = 531.172180
last_seq = 7458
current_ts = 531.183716
current_received_ts = 531.183350
current_seq = 7459
count = 598
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.172546/7458, current 531.183716/7459: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.172546/7458, current 531.183716/7459: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.183716
last_received_ts = 531.183350
last_seq = 7459
current_ts = 531.194885
current_received_ts = 531.194519
current_seq = 7460
count = 599
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.183716/7459, current 531.194885/7460: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.183716/7459, current 531.194885/7460: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.194885
last_received_ts = 531.194519
last_seq = 7460
current_ts = 531.206055
current_received_ts = 531.205627
current_seq = 7461
count = 600
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.194885/7460, current 531.206055/7461: elapsed=11163.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.194885/7460, current 531.206055/7461: elapsed=11163.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.206055
last_received_ts = 531.205627
last_seq = 7461
current_ts = 531.217163
current_received_ts = 531.216797
current_seq = 7462
count = 601
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.206055/7461, current 531.217163/7462: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.206055/7461, current 531.217163/7462: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.217163
last_received_ts = 531.216797
last_seq = 7462
current_ts = 531.228333
current_received_ts = 531.227966
current_seq = 7463
count = 602
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.217163/7462, current 531.228333/7463: elapsed=11162.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.217163/7462, current 531.228333/7463: elapsed=11162.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.228333
last_received_ts = 531.227966
last_seq = 7463
current_ts = 531.239502
current_received_ts = 531.239075
current_seq = 7464
count = 603
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.228333/7463, current 531.239502/7464: elapsed=11157.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.228333/7463, current 531.239502/7464: elapsed=11157.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.239502
last_received_ts = 531.239075
last_seq = 7464
current_ts = 531.250671
current_received_ts = 531.250305
current_seq = 7465
count = 604
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.239502/7464, current 531.250671/7465: elapsed=11160.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.239502/7464, current 531.250671/7465: elapsed=11160.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.250671
last_received_ts = 531.250305
last_seq = 7465
current_ts = 531.261841
current_received_ts = 531.261414
current_seq = 7466
count = 605
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.250671/7465, current 531.261841/7466: elapsed=11158.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.250671/7465, current 531.261841/7466: elapsed=11158.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.261841
last_received_ts = 531.261414
last_seq = 7466
current_ts = 531.273010
current_received_ts = 531.272583
current_seq = 7467
count = 606
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.261841/7466, current 531.273010/7467: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.261841/7466, current 531.273010/7467: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.273010
last_received_ts = 531.272583
last_seq = 7467
current_ts = 531.284119
current_received_ts = 531.283752
current_seq = 7468
count = 607
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.273010/7467, current 531.284119/7468: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.273010/7467, current 531.284119/7468: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.284119
last_received_ts = 531.283752
last_seq = 7468
current_ts = 531.295288
current_received_ts = 531.294922
current_seq = 7469
count = 608
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.284119/7468, current 531.295288/7469: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.284119/7468, current 531.295288/7469: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.295288
last_received_ts = 531.294922
last_seq = 7469
current_ts = 531.306458
current_received_ts = 531.306091
current_seq = 7470
count = 609
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.295288/7469, current 531.306458/7470: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.295288/7469, current 531.306458/7470: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.306458
last_received_ts = 531.306091
last_seq = 7470
current_ts = 531.317627
current_received_ts = 531.317200
current_seq = 7471
count = 610
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.306458/7470, current 531.317627/7471: elapsed=11160.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.306458/7470, current 531.317627/7471: elapsed=11160.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.317627
last_received_ts = 531.317200
last_seq = 7471
current_ts = 531.328796
current_received_ts = 531.328369
current_seq = 7472
count = 611
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.317627/7471, current 531.328796/7472: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.317627/7471, current 531.328796/7472: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.328796
last_received_ts = 531.328369
last_seq = 7472
current_ts = 531.339966
current_received_ts = 531.339600
current_seq = 7473
count = 612
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.328796/7472, current 531.339966/7473: elapsed=11160.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.328796/7472, current 531.339966/7473: elapsed=11160.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.339966
last_received_ts = 531.339600
last_seq = 7473
current_ts = 531.351074
current_received_ts = 531.350708
current_seq = 7474
count = 613
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.339966/7473, current 531.351074/7474: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.339966/7473, current 531.351074/7474: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.351074
last_received_ts = 531.350708
last_seq = 7474
current_ts = 531.362244
current_received_ts = 531.361877
current_seq = 7475
count = 614
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.351074/7474, current 531.362244/7475: elapsed=11156.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.351074/7474, current 531.362244/7475: elapsed=11156.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.362244
last_received_ts = 531.361877
last_seq = 7475
current_ts = 531.373413
current_received_ts = 531.373047
current_seq = 7476
count = 615
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.362244/7475, current 531.373413/7476: elapsed=11160.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.362244/7475, current 531.373413/7476: elapsed=11160.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.373413
last_received_ts = 531.373047
last_seq = 7476
current_ts = 531.384583
current_received_ts = 531.384155
current_seq = 7477
count = 616
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.373413/7476, current 531.384583/7477: elapsed=11161.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.373413/7476, current 531.384583/7477: elapsed=11161.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.384583
last_received_ts = 531.384155
last_seq = 7477
current_ts = 531.395752
current_received_ts = 531.395325
current_seq = 7478
count = 617
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.384583/7477, current 531.395752/7478: elapsed=11156.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.384583/7477, current 531.395752/7478: elapsed=11156.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.395752
last_received_ts = 531.395325
last_seq = 7478
current_ts = 531.406860
current_received_ts = 531.406494
current_seq = 7479
count = 618
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.395752/7478, current 531.406860/7479: elapsed=11160.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.395752/7478, current 531.406860/7479: elapsed=11160.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.406860
last_received_ts = 531.406494
last_seq = 7479
current_ts = 531.418030
current_received_ts = 531.417664
current_seq = 7480
count = 619
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.406860/7479, current 531.418030/7480: elapsed=11156.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.406860/7479, current 531.418030/7480: elapsed=11156.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.418030
last_received_ts = 531.417664
last_seq = 7480
current_ts = 531.429199
current_received_ts = 531.428833
current_seq = 7481
count = 620
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.418030/7480, current 531.429199/7481: elapsed=11164.0us expected=11221.1us +- 56.1us, error 0.5%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.418030/7480, current 531.429199/7481: elapsed=11164.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.429199
last_received_ts = 531.428833
last_seq = 7481
current_ts = 531.440369
current_received_ts = 531.440002
current_seq = 7482
count = 621
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.429199/7481, current 531.440369/7482: elapsed=11157.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.429199/7481, current 531.440369/7482: elapsed=11157.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.440369
last_received_ts = 531.440002
last_seq = 7482
current_ts = 531.451538
current_received_ts = 531.451111
current_seq = 7483
count = 622
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.440369/7482, current 531.451538/7483: elapsed=11151.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.440369/7482, current 531.451538/7483: elapsed=11151.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.451538
last_received_ts = 531.451111
last_seq = 7483
current_ts = 531.462646
current_received_ts = 531.462280
current_seq = 7484
count = 623
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.451538/7483, current 531.462646/7484: elapsed=11157.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.451538/7483, current 531.462646/7484: elapsed=11157.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.462646
last_received_ts = 531.462280
last_seq = 7484
current_ts = 531.473816
current_received_ts = 531.473450
current_seq = 7485
count = 624
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.462646/7484, current 531.473816/7485: elapsed=11152.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.462646/7484, current 531.473816/7485: elapsed=11152.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.473816
last_received_ts = 531.473450
last_seq = 7485
current_ts = 531.484985
current_received_ts = 531.484558
current_seq = 7486
count = 625
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.473816/7485, current 531.484985/7486: elapsed=11150.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.473816/7485, current 531.484985/7486: elapsed=11150.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.484985
last_received_ts = 531.484558
last_seq = 7486
current_ts = 531.496155
current_received_ts = 531.495728
current_seq = 7487
count = 626
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.484985/7486, current 531.496155/7487: elapsed=11159.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.484985/7486, current 531.496155/7487: elapsed=11159.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.496155
last_received_ts = 531.495728
last_seq = 7487
current_ts = 531.507263
current_received_ts = 531.506897
current_seq = 7488
count = 627
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.496155/7487, current 531.507263/7488: elapsed=11149.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.496155/7487, current 531.507263/7488: elapsed=11149.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.507263
last_received_ts = 531.506897
last_seq = 7488
current_ts = 531.518433
current_received_ts = 531.518005
current_seq = 7489
count = 628
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.507263/7488, current 531.518433/7489: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.507263/7488, current 531.518433/7489: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.518433
last_received_ts = 531.518005
last_seq = 7489
current_ts = 531.529602
current_received_ts = 531.529175
current_seq = 7490
count = 629
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.518433/7489, current 531.529602/7490: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.518433/7489, current 531.529602/7490: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.529602
last_received_ts = 531.529175
last_seq = 7490
current_ts = 531.540771
current_received_ts = 531.540344
current_seq = 7491
count = 630
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.529602/7490, current 531.540771/7491: elapsed=11153.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.529602/7490, current 531.540771/7491: elapsed=11153.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.540771
last_received_ts = 531.540344
last_seq = 7491
current_ts = 531.551880
current_received_ts = 531.551514
current_seq = 7492
count = 631
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.540771/7491, current 531.551880/7492: elapsed=11152.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.540771/7491, current 531.551880/7492: elapsed=11152.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.551880
last_received_ts = 531.551514
last_seq = 7492
current_ts = 531.563049
current_received_ts = 531.562683
current_seq = 7493
count = 632
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.551880/7492, current 531.563049/7493: elapsed=11157.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.551880/7492, current 531.563049/7493: elapsed=11157.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.563049
last_received_ts = 531.562683
last_seq = 7493
current_ts = 531.574219
current_received_ts = 531.573792
current_seq = 7494
count = 633
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.563049/7493, current 531.574219/7494: elapsed=11151.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.563049/7493, current 531.574219/7494: elapsed=11151.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.574219
last_received_ts = 531.573792
last_seq = 7494
current_ts = 531.585388
current_received_ts = 531.584961
current_seq = 7495
count = 634
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.574219/7494, current 531.585388/7495: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.574219/7494, current 531.585388/7495: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.585388
last_received_ts = 531.584961
last_seq = 7495
current_ts = 531.596497
current_received_ts = 531.596130
current_seq = 7496
count = 635
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.585388/7495, current 531.596497/7496: elapsed=11150.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.585388/7495, current 531.596497/7496: elapsed=11150.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.596497
last_received_ts = 531.596130
last_seq = 7496
current_ts = 531.607666
current_received_ts = 531.607300
current_seq = 7497
count = 636
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.596497/7496, current 531.607666/7497: elapsed=11156.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.596497/7496, current 531.607666/7497: elapsed=11156.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.607666
last_received_ts = 531.607300
last_seq = 7497
current_ts = 531.618835
current_received_ts = 531.618408
current_seq = 7498
count = 637
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.607666/7497, current 531.618835/7498: elapsed=11156.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.607666/7497, current 531.618835/7498: elapsed=11156.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.618835
last_received_ts = 531.618408
last_seq = 7498
current_ts = 531.629944
current_received_ts = 531.629578
current_seq = 7499
count = 638
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.618835/7498, current 531.629944/7499: elapsed=11151.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.618835/7498, current 531.629944/7499: elapsed=11151.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.629944
last_received_ts = 531.629578
last_seq = 7499
current_ts = 531.641113
current_received_ts = 531.640747
current_seq = 7500
count = 639
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.629944/7499, current 531.641113/7500: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.629944/7499, current 531.641113/7500: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.641113
last_received_ts = 531.640747
last_seq = 7500
current_ts = 531.652283
current_received_ts = 531.651855
current_seq = 7501
count = 640
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.641113/7500, current 531.652283/7501: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.641113/7500, current 531.652283/7501: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.652283
last_received_ts = 531.651855
last_seq = 7501
current_ts = 531.663452
current_received_ts = 531.663086
current_seq = 7502
count = 641
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.652283/7501, current 531.663452/7502: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.652283/7501, current 531.663452/7502: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.663452
last_received_ts = 531.663086
last_seq = 7502
current_ts = 531.674561
current_received_ts = 531.674194
current_seq = 7503
count = 642
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.663452/7502, current 531.674561/7503: elapsed=11150.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.663452/7502, current 531.674561/7503: elapsed=11150.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.674561
last_received_ts = 531.674194
last_seq = 7503
current_ts = 531.685730
current_received_ts = 531.685364
current_seq = 7504
count = 643
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.674561/7503, current 531.685730/7504: elapsed=11157.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.674561/7503, current 531.685730/7504: elapsed=11157.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.685730
last_received_ts = 531.685364
last_seq = 7504
current_ts = 531.696899
current_received_ts = 531.696533
current_seq = 7505
count = 644
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.685730/7504, current 531.696899/7505: elapsed=11153.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.685730/7504, current 531.696899/7505: elapsed=11153.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.696899
last_received_ts = 531.696533
last_seq = 7505
current_ts = 531.708069
current_received_ts = 531.707642
current_seq = 7506
count = 645
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.696899/7505, current 531.708069/7506: elapsed=11151.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.696899/7505, current 531.708069/7506: elapsed=11151.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.708069
last_received_ts = 531.707642
last_seq = 7506
current_ts = 531.719177
current_received_ts = 531.718811
current_seq = 7507
count = 646
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.708069/7506, current 531.719177/7507: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.708069/7506, current 531.719177/7507: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.719177
last_received_ts = 531.718811
last_seq = 7507
current_ts = 531.730347
current_received_ts = 531.729980
current_seq = 7508
count = 647
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.719177/7507, current 531.730347/7508: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.719177/7507, current 531.730347/7508: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.730347
last_received_ts = 531.729980
last_seq = 7508
current_ts = 531.741516
current_received_ts = 531.741089
current_seq = 7509
count = 648
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.730347/7508, current 531.741516/7509: elapsed=11153.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.730347/7508, current 531.741516/7509: elapsed=11153.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.741516
last_received_ts = 531.741089
last_seq = 7509
current_ts = 531.752686
current_received_ts = 531.752258
current_seq = 7510
count = 649
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.741516/7509, current 531.752686/7510: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.741516/7509, current 531.752686/7510: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.752686
last_received_ts = 531.752258
last_seq = 7510
current_ts = 531.763794
current_received_ts = 531.763428
current_seq = 7511
count = 650
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.752686/7510, current 531.763794/7511: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.752686/7510, current 531.763794/7511: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.763794
last_received_ts = 531.763428
last_seq = 7511
current_ts = 531.774963
current_received_ts = 531.774597
current_seq = 7512
count = 651
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.763794/7511, current 531.774963/7512: elapsed=11153.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.763794/7511, current 531.774963/7512: elapsed=11153.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.774963
last_received_ts = 531.774597
last_seq = 7512
current_ts = 531.786133
current_received_ts = 531.785767
current_seq = 7513
count = 652
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.774963/7512, current 531.786133/7513: elapsed=11153.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.774963/7512, current 531.786133/7513: elapsed=11153.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.786133
last_received_ts = 531.785767
last_seq = 7513
current_ts = 531.797302
current_received_ts = 531.796875
current_seq = 7514
count = 653
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.786133/7513, current 531.797302/7514: elapsed=11152.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.786133/7513, current 531.797302/7514: elapsed=11152.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.797302
last_received_ts = 531.796875
last_seq = 7514
current_ts = 531.808411
current_received_ts = 531.808044
current_seq = 7515
count = 654
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.797302/7514, current 531.808411/7515: elapsed=11156.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.797302/7514, current 531.808411/7515: elapsed=11156.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.808411
last_received_ts = 531.808044
last_seq = 7515
current_ts = 531.819580
current_received_ts = 531.819214
current_seq = 7516
count = 655
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.808411/7515, current 531.819580/7516: elapsed=11150.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.808411/7515, current 531.819580/7516: elapsed=11150.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.819580
last_received_ts = 531.819214
last_seq = 7516
current_ts = 531.830750
current_received_ts = 531.830322
current_seq = 7517
count = 656
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.819580/7516, current 531.830750/7517: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.819580/7516, current 531.830750/7517: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.830750
last_received_ts = 531.830322
last_seq = 7517
current_ts = 531.841858
current_received_ts = 531.841492
current_seq = 7518
count = 657
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.830750/7517, current 531.841858/7518: elapsed=11151.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.830750/7517, current 531.841858/7518: elapsed=11151.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.841858
last_received_ts = 531.841492
last_seq = 7518
current_ts = 531.853027
current_received_ts = 531.852661
current_seq = 7519
count = 658
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.841858/7518, current 531.853027/7519: elapsed=11156.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.841858/7518, current 531.853027/7519: elapsed=11156.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.853027
last_received_ts = 531.852661
last_seq = 7519
current_ts = 531.864197
current_received_ts = 531.863770
current_seq = 7520
count = 659
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.853027/7519, current 531.864197/7520: elapsed=11153.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.853027/7519, current 531.864197/7520: elapsed=11153.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.864197
last_received_ts = 531.863770
last_seq = 7520
current_ts = 531.875366
current_received_ts = 531.874939
current_seq = 7521
count = 660
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.864197/7520, current 531.875366/7521: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.864197/7520, current 531.875366/7521: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.875366
last_received_ts = 531.874939
last_seq = 7521
current_ts = 531.886475
current_received_ts = 531.886108
current_seq = 7522
count = 661
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.875366/7521, current 531.886475/7522: elapsed=11152.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.875366/7521, current 531.886475/7522: elapsed=11152.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.886475
last_received_ts = 531.886108
last_seq = 7522
current_ts = 531.897644
current_received_ts = 531.897278
current_seq = 7523
count = 662
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.886475/7522, current 531.897644/7523: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.886475/7522, current 531.897644/7523: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.897644
last_received_ts = 531.897278
last_seq = 7523
current_ts = 531.908813
current_received_ts = 531.908386
current_seq = 7524
count = 663
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.897644/7523, current 531.908813/7524: elapsed=11152.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.897644/7523, current 531.908813/7524: elapsed=11152.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.908813
last_received_ts = 531.908386
last_seq = 7524
current_ts = 531.919983
current_received_ts = 531.919617
current_seq = 7525
count = 664
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.908813/7524, current 531.919983/7525: elapsed=11152.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.908813/7524, current 531.919983/7525: elapsed=11152.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.919983
last_received_ts = 531.919617
last_seq = 7525
current_ts = 531.931091
current_received_ts = 531.930725
current_seq = 7526
count = 665
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.919983/7525, current 531.931091/7526: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.919983/7525, current 531.931091/7526: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.931091
last_received_ts = 531.930725
last_seq = 7526
current_ts = 531.942261
current_received_ts = 531.941895
current_seq = 7527
count = 666
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.931091/7526, current 531.942261/7527: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.931091/7526, current 531.942261/7527: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.942261
last_received_ts = 531.941895
last_seq = 7527
current_ts = 531.953430
current_received_ts = 531.953064
current_seq = 7528
count = 667
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.942261/7527, current 531.953430/7528: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.942261/7527, current 531.953430/7528: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.953430
last_received_ts = 531.953064
last_seq = 7528
current_ts = 531.964600
current_received_ts = 531.964172
current_seq = 7529
count = 668
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.953430/7528, current 531.964600/7529: elapsed=11154.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.953430/7528, current 531.964600/7529: elapsed=11154.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.964600
last_received_ts = 531.964172
last_seq = 7529
current_ts = 531.975708
current_received_ts = 531.975342
current_seq = 7530
count = 669
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.964600/7529, current 531.975708/7530: elapsed=11155.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.964600/7529, current 531.975708/7530: elapsed=11155.0us expected=11221.1us
(kms_flip:2918) DEBUG: name = flip
last_ts = 531.975708
last_received_ts = 531.975342
last_seq = 7530
current_ts = 531.986877
current_received_ts = 531.986511
current_seq = 7531
count = 670
seq_step = 1
(kms_flip:2918) DEBUG: flip ts/seq: last 531.975708/7530, current 531.986877/7531: elapsed=11153.0us expected=11221.1us +- 56.1us, error 0.6%
(kms_flip:2918) DEBUG: inconsistent flip ts/seq: last 531.975708/7530, current 531.986877/7531: elapsed=11153.0us expected=11221.1us
(kms_flip:2918) INFO: Event flip: expected 668, counted 671, passrate = 70.19%, encoder type 2
(kms_flip:2918) DEBUG: dropped frames, expected 668, counted 671, passrate = 70.19%, encoder type 2
(kms_flip:2918) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1707:
(kms_flip:2918) CRITICAL: Failed assertion: !retried
(kms_flip:2918) igt_core-INFO: Stack trace:
(kms_flip:2918) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2918) igt_core-INFO:   #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
(kms_flip:2918) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:2918) igt_core-INFO:   #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043()
(kms_flip:2918) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:2918) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2918) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2918) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (20.767s)
Dmesg
<6> [540.486306] Console: switching to colour dummy device 80x25
<6> [540.486754] [IGT] kms_flip: executing
<7> [540.494752] i915 0000:00:02.0: [drm:i915_gem_open [i915]]
<7> [540.496300] i915 0000:00:02.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x000001dc [0x000001dc]
<7> [540.515089] i915 0000:00:02.0: [drm:i915_gem_open [i915]]
<7> [540.525973] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:516:DP-1]
<7> [540.525985] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:516:DP-1]
<7> [540.530279] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:516:DP-1] disconnected
<7> [540.530727] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:528:HDMI-A-1]
<7> [540.530734] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:528:HDMI-A-1]
<7> [540.535076] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:528:HDMI-A-1] disconnected
<7> [540.535482] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:534:DP-2]
<7> [540.535487] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:534:DP-2]
<7> [540.535859] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:534:DP-2] disconnected
<7> [540.536241] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:543:HDMI-A-2]
<7> [540.536245] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:543:HDMI-A-2]
<7> [540.540622] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:543:HDMI-A-2] disconnected
<7> [540.540911] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:547:DP-3]
<7> [540.540915] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:547:DP-3]
<7> [540.541176] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:547:DP-3] disconnected
<7> [540.541428] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:556:DP-4]
<7> [540.541430] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:556:DP-4]
<7> [540.541704] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:556:DP-4] disconnected
<7> [540.542064] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:507:eDP-1]
<7> [540.542067] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:507:eDP-1]
<7> [540.542649] i915 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [i915]] DSC DPCD: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
<7> [540.543314] i915 0000:00:02.0: [drm:intel_dp_print_rates [i915]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000
<7> [540.543465] i915 0000:00:02.0: [drm:intel_dp_print_rates [i915]] sink rates: 162000, 216000, 243000, 270000, 324000, 378000, 432000, 540000
<7> [540.543608] i915 0000:00:02.0: [drm:intel_dp_print_rates [i915]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000
<7> [540.543768] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:507:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc.
<7> [540.543773] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:507:eDP-1] ELD monitor
<7> [540.543775] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:507:eDP-1] ELD size 20, SAD count 0
<7> [540.543791] i915 0000:00:02.0: [drm:intel_dp_set_edid [i915]] [CONNECTOR:507:eDP-1] VRR capable: no
<7> [540.543927] i915 0000:00:02.0: [drm:intel_dp_set_edid [i915]] [CONNECTOR:507:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps
<7> [540.544055] i915 0000:00:02.0: [drm:intel_dp_set_edid [i915]] [CONNECTOR:507:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no
<7> [540.545191] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:507:eDP-1] probed modes:
<7> [540.545195] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa
<7> [540.545209] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:516:DP-1]
<7> [540.545212] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:516:DP-1]
<7> [540.549429] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:516:DP-1] disconnected
<7> [540.549442] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:528:HDMI-A-1]
<7> [540.549445] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:528:HDMI-A-1]
<7> [540.553657] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:528:HDMI-A-1] disconnected
<7> [540.553668] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:534:DP-2]
<7> [540.553670] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:534:DP-2]
<7> [540.553940] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:534:DP-2] disconnected
<7> [540.553948] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:543:HDMI-A-2]
<7> [540.553950] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:543:HDMI-A-2]
<7> [540.558254] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:543:HDMI-A-2] disconnected
<7> [540.558275] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:547:DP-3]
<7> [540.558278] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:547:DP-3]
<7> [540.559201] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:547:DP-3] disconnected
<7> [540.559255] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:556:DP-4]
<7> [540.559265] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:556:DP-4]
<7> [540.560067] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:556:DP-4] disconnected
<6> [540.561616] [IGT] kms_flip: starting subtest plain-flip-ts-check
<6> [540.564213] [IGT] kms_flip: starting dynamic subtest A-eDP1
<7> [540.564789] i915 0000:00:02.0: [drm:i915_dpt_create [i915]] Allocating dpt from smem
<7> [540.564970] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:565]
<7> [540.565046] i915 0000:00:02.0: [drm:i915_dpt_create [i915]] Allocating dpt from smem
<7> [540.565192] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:567]
<7> [540.568139] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [540.568515] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [540.595494] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [540.595791] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [540.604241] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [540.604544] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [540.623176] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [540.623506] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [540.648706] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]
<7> [540.648801] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [540.648968] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [540.649117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [540.649262] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [540.649425] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 7483046/8388608 link 498869/524288, found tu 0, data 0/0 link 0/0)
<7> [540.649571] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [540.649714] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [540.649857] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [540.649998] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [540.650139] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [540.650279] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [540.650436] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [540.650593] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [540.650733] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [540.650875] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1801, found 0)
<7> [540.651014] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [540.651153] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [540.651292] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1878, found 0)
<7> [540.651439] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1878, found 0)
<7> [540.651577] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [540.651716] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [540.651858] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [540.652091] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [540.652236] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [540.652376] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [540.652537] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [540.652674] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1801, found 0)
<7> [540.652811] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [540.652950] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [540.653088] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1878, found 0)
<7> [540.653227] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1878, found 0)
<7> [540.653364] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [540.653528] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [540.653671] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [540.653808] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no)
<7> [540.653946] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [540.654105] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 513820, found 0)
<7> [540.654253] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 513820, found 0)
<7> [540.654396] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 540000, found 0)
<7> [540.654571] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in set_context_latency (expected 1, found 0)
<7> [540.654724] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset
<7> [540.654903] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:150:pipe A] releasing DPLL 0
<7> [540.655149] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [540.655310] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:150:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [540.655483] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:34:plane 1A] ddb ( 0 - 4001) -> ( 0 - 0), size 4001 -> 0
<7> [540.655615] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:144:cursor A] ddb (4001 - 4096) -> ( 0 - 0), size 95 -> 0
<7> [540.655747] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [540.655876] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] lines 2, 16, 16, 19, 19, 28, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [540.656006] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] blocks 49, 385, 385, 457, 457, 673, 0, 0, 63, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [540.656137] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] min_ddb 55, 425, 425, 504, 504, 742, 0, 0, 64, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [540.656282] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:150:pipe A] data rate 0 num active planes 0
<7> [540.656441] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 28913 required 0 qgv_peak_bw: 51200
<7> [540.656589] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 1: max bw 38000 required 0 qgv_peak_bw: 51200
<7> [540.656736] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 51200
<7> [540.656876] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 51200
<7> [540.657015] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] Matching peaks QGV bw: 51200 for required data rate: 0
<7> [540.657154] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:150:pipe A] min cdclk: 256910 kHz -> 0 kHz
<7> [540.657343] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 32114 kHz -> 0 kHz
<7> [540.657555] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Can change cdclk via squashing
<7> [540.657729] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 172800 kHz, actual 172800 kHz
<7> [540.657890] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [540.658059] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:150:pipe A] enable: no [modeset]
<7> [540.658220] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:plane 1A] fb: [NOFB], visible: no
<7> [540.658375] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:64:plane 2A] fb: [NOFB], visible: no
<7> [540.658540] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:94:plane 3A] fb: [NOFB], visible: no
<7> [540.658681] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:124:plane 4A] fb: [NOFB], visible: no
<7> [540.658818] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:134:plane 5A] fb: [NOFB], visible: no
<7> [540.658954] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:144:cursor A] fb: [NOFB], visible: no
<7> [540.659137] i915 0000:00:02.0: [drm:intel_psr_disable_locked [i915]] Disabling PSR2
<7> [540.659997] i915 0000:00:02.0: [drm:intel_edp_backlight_off [i915]]
<7> [540.859028] i915 0000:00:02.0: [drm:intel_backlight_set_pwm_level [i915]] [CONNECTOR:507:eDP-1] set backlight PWM = 0
<7> [540.860003] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [540.872903] i915 0000:00:02.0: [drm:intel_pps_off_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turn panel power off
<7> [540.873233] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x00000089, pins 0x00000010, long 0x00000000
<7> [540.873463] i915 0000:00:02.0: [drm:intel_pps_off_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [540.873790] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:506:DDI A/PHY A] - short
<7> [540.874016] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [540.925942] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x0000008a, pins 0x00000010, long 0x00000010
<7> [540.926497] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:506:DDI A/PHY A] - long
<7> [540.926997] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [540.933022] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete
<7> [540.933577] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:150:pipe A]
<7> [540.933705] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring short hpd on eDP [ENCODER:506:DDI A/PHY A]
<7> [540.934223] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP [ENCODER:506:DDI A/PHY A]
<7> [540.935148] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [540.935689] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling AUX_A
<7> [540.936126] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:506:DDI A/PHY A]
<7> [540.936383] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:515:DDI B/PHY B]
<7> [540.936600] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:517:DP-MST A]
<7> [540.936837] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:518:DP-MST B]
<7> [540.937065] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DP-MST C]
<7> [540.937278] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DP-MST D]
<7> [540.937415] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:533:DDI TC1/PHY TC1]
<7> [540.937542] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DP-MST A]
<7> [540.937671] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:536:DP-MST B]
<7> [540.937815] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST C]
<7> [540.937943] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST D]
<7> [540.938069] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:542:DDI TC2/PHY TC2]
<7> [540.938195] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:546:DDI TC3/PHY TC3]
<7> [540.938320] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:548:DP-MST A]
<7> [540.938444] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST B]
<7> [540.938569] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST C]
<7> [540.938749] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST D]
<7> [540.938876] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:555:DDI TC4/PHY TC4]
<7> [540.939000] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:557:DP-MST A]
<7> [540.939122] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:558:DP-MST B]
<7> [540.939243] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:559:DP-MST C]
<7> [540.939365] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:560:DP-MST D]
<7> [540.939488] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:507:eDP-1]
<7> [540.939689] i915 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [i915]] Updating dbuf ratio to 2 (mbus joined: no)
<7> [540.939839] i915 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [i915]] Changing mbus joined: yes -> no (pipe: *)
<7> [540.939975] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [540.940234] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_A
<7> [540.940381] i915 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [i915]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [540.940603] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:150:pipe A]
<7> [540.940804] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Post changing CDCLK to 172800 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [540.940983] i915 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=432
<7> [540.941389] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]
<7> [540.941596] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:386:pipe C]
<7> [540.941728] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:504:pipe D]
<7> [540.941849] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]
<7> [540.941884] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:507:eDP-1]
<7> [540.941950] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:507:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [540.942101] i915 0000:00:02.0: [drm:intel_dp_compute_config_limits [i915]] [ENCODER:506:DDI A/PHY A][CRTC:150:pipe A] DP link limits: pixel clock 513820 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000
<7> [540.942227] i915 0000:00:02.0: [drm:intel_dp_compute_link_config [i915]] DP lane count 4 clock 540000 bpp input 30 compressed 0.0000 HDR no link rate required 1926825 available 2160000
<7> [540.942360] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [540.942512] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:506:DDI A/PHY A] [CRTC:150:pipe A]
<7> [540.942638] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [540.942771] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [540.942905] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [540.943036] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [540.943175] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 7483046/8388608 link 498869/524288)
<7> [540.943308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [540.943456] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [540.943588] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [540.943725] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [540.943855] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [540.943985] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [540.944116] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [540.944247] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [540.944419] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [540.944554] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1801)
<7> [540.944685] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [540.944815] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [540.944946] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1878)
<7> [540.945075] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1878)
<7> [540.945203] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [540.945337] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [540.945469] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [540.945597] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [540.945727] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [540.945858] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [540.945986] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [540.946113] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1801)
<7> [540.946240] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [540.946395] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [540.946530] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1878)
<7> [540.946658] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1878)
<7> [540.946784] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [540.946918] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [540.947065] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [540.947199] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in enhanced_framing (expected no, found yes)
<7> [540.947353] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [540.947480] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 513820)
<7> [540.947607] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 513820)
<7> [540.947732] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 540000)
<7> [540.947858] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in set_context_latency (expected 0, found 1)
<7> [540.947984] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset
<7> [540.948139] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [540.948285] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1
<7> [540.948433] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4001), size 0 -> 4001
<7> [540.948564] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4001 - 4096), size 0 -> 95
<7> [540.948685] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [540.948806] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 16, 16, 19, 19, 28, 0, 0, 0, 4, 0
<7> [540.948927] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 365, 365, 434, 434, 638, 0, 0, 197, 92, 197
<7> [540.949061] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 547, 547, 729, 0, 0, 198, 183, 198
<7> [540.949222] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:150:pipe A] data rate 2055280 num active planes 1
<7> [540.949384] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 28913 required 2159 qgv_peak_bw: 51200
<7> [540.949518] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 1: max bw 38000 required 2159 qgv_peak_bw: 51200
<7> [540.949666] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 2: max bw 38000 required 2159 qgv_peak_bw: 51200
<7> [540.949812] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 3: max bw 38000 required 2159 qgv_peak_bw: 51200
<7> [540.949945] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] Matching peaks QGV bw: 51200 for required data rate: 2159
<7> [540.950076] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 256910 kHz
<7> [540.950245] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 32114 kHz
<7> [540.950376] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Can change cdclk via squashing
<7> [540.950506] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 307200 kHz, actual 307200 kHz
<7> [540.950635] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [540.950774] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:150:pipe A] allocated DPLL 0
<7> [540.950905] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:150:pipe A] reserving DPLL 0
<7> [540.951044] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:150:pipe A] enable: yes [modeset]
<7> [540.951181] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [540.951321] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [540.951451] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [540.951583] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [540.951712] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [540.951849] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [540.952005] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dp m_n: lanes: 4; data_m: 7483046, data_n: 8388608, link_m: 498869, link_n: 524288, tu: 64
<7> [540.952166] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [540.952297] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fec: disabled, enhanced framing: enabled
<7> [540.952441] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sdp split: disabled
<7> [540.952588] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [540.952721] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] minimum HBlank: 0
<7> [540.952853] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [540.953000] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] DP SDP: VSC, revision 4, length 14
<7> [540.953132] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pixelformat: RGB
<7> [540.953258] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] colorimetry: sRGB
<7> [540.953384] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] bpc: 0
<7> [540.953511] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dynamic range: VESA range
<7> [540.953638] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] content type: Not defined
<7> [540.953765] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1
<7> [540.953892] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 1
<7> [540.954050] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1878, vmax: 1878, flipline: 1878, pipeline full: 0, guardband: 76 vsync start: 75, vsync end: 69
<7> [540.954181] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1878, vmax vtotal: 1878
<7> [540.954310] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [540.954438] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa
<7> [540.954573] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa
<7> [540.954714] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=513820, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1801-1878 vs=1803-1809 vt=1878, flags=0xa
<7> [540.954871] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x40 0xa
<7> [540.955000] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=513820, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1801-1878 vs=1803-1809 vt=1878, flags=0xa
<7> [540.955135] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 540000, pipe src: 2880x1800+0+0, pixel rate 513820, min cdclk 256910
<7> [540.955284] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 48, ips linetime: 0
<7> [540.955414] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [540.955542] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [540.955670] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [540.955798] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no
<7> [540.955983] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] c10pll_hw_state: fracen: yes,
<7> [540.956110] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] quot: 40960, rem: 0, den: 1,
<7> [540.956236] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] multiplier: 140, tx_clk_div: 0.
<7> [540.956362] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] c10pll_rawhw_state:
<7> [540.956487] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] tx: 0x10, cmn: 0x21
<7> [540.956613] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[0] = 0xf4, pll[1] = 0x0, pll[2] = 0xf8, pll[3] = 0x0
<7> [540.956749] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [540.956903] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [540.957036] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[12] = 0xa0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x0
<7> [540.957165] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[16] = 0x84, pll[17] = 0x4f, pll[18] = 0xe5, pll[19] = 0x23
<7> [540.957301] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [540.957449] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [540.957595] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [540.957734] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [540.957861] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [540.958022] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [540.958150] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [540.958278] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [540.958405] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [540.958533] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [540.958662] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [540.958818] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [540.958844] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [540.958944] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [540.959069] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:plane 1A] fb: [FB:565] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [540.959093] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [540.959197] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [540.959322] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [540.959306] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02
<7> [540.959447] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:64:plane 2A] fb: [NOFB], visible: no
<7> [540.959579] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:94:plane 3A] fb: [NOFB], visible: no
<7> [540.959726] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:124:plane 4A] fb: [NOFB], visible: no
<7> [540.959851] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:134:plane 5A] fb: [NOFB], visible: no
<7> [540.959975] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:144:cursor A] fb: [NOFB], visible: no
<7> [540.964072] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [540.964818] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 02 to 00
<7> [540.965588] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [540.966009] i915 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [i915]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)
<7> [540.966545] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 307200 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [540.967119] i915 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=768
<7> [540.967648] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:506:DDI A/PHY A]
<7> [540.968111] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:515:DDI B/PHY B]
<7> [540.968602] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:517:DP-MST A]
<7> [540.969043] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:518:DP-MST B]
<7> [540.969460] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DP-MST C]
<7> [540.969844] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DP-MST D]
<7> [540.970249] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:533:DDI TC1/PHY TC1]
<7> [540.970623] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DP-MST A]
<7> [540.970955] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:536:DP-MST B]
<7> [540.971137] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST C]
<7> [540.971311] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST D]
<7> [540.971484] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:542:DDI TC2/PHY TC2]
<7> [540.971657] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:546:DDI TC3/PHY TC3]
<7> [540.971830] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:548:DP-MST A]
<7> [540.972003] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST B]
<7> [540.972192] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST C]
<7> [540.972369] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST D]
<7> [540.972541] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:555:DDI TC4/PHY TC4]
<7> [540.972714] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:557:DP-MST A]
<7> [540.972878] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:558:DP-MST B]
<7> [540.973016] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:559:DP-MST C]
<7> [540.973150] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:560:DP-MST D]
<7> [540.973312] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xf
<7> [540.973553] i915 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [i915]] Changing mbus joined: no -> yes (pipe: *)
<7> [540.973697] i915 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [i915]] Updating dbuf ratio to 4 (mbus joined: yes)
<7> [540.973911] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling AUX_A
<7> [540.975381] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:150:pipe A]
<7> [540.975552] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [540.977329] i915 0000:00:02.0: [drm:intel_pps_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turn panel power on
<7> [540.977489] i915 0000:00:02.0: [drm:wait_panel_power_cycle [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 wait for panel power cycle (454 ms remaining)
<7> [541.416458] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [541.516085] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete
<7> [541.517170] i915 0000:00:02.0: [drm:intel_pps_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 wait for panel power on
<7> [541.518009] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [541.549921] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x0000008a, pins 0x00000010, long 0x00000010
<7> [541.550543] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:506:DDI A/PHY A] - long
<7> [541.551045] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [541.551716] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP [ENCODER:506:DDI A/PHY A]
<7> [541.560894] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port E/TC#2: TC port mode reset (legacy -> disconnected) pin assignment: - max lanes: 4
<7> [541.560963] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port G/TC#4: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [541.561087] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [541.561607] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [541.726174] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete
<7> [541.727294] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turning VDD on
<7> [541.728060] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [541.731248] i915 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 14 c4 41 00 00 01 c0 02 00 00 00 00 0b 80
<7> [541.732396] i915 0000:00:02.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [541.732997] i915 0000:00:02.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 07
<7> [541.734073] i915 0000:00:02.0: [drm:intel_dp_set_signal_levels [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [541.734957] i915 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [541.735920] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Clock recovery OK
<7> [541.736046] i915 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Using DP training pattern TPS3
<7> [541.737349] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [541.737481] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Link Training passed at link rate = 540000, lane count = 4
<7> [541.738083] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [541.738396] i915 0000:00:02.0: [drm:intel_edp_backlight_on [i915]]
<7> [541.738532] i915 0000:00:02.0: [drm:intel_backlight_enable [i915]] pipe A
<7> [541.738713] i915 0000:00:02.0: [drm:intel_backlight_set_pwm_level [i915]] [CONNECTOR:507:eDP-1] set backlight PWM = 4518
<7> [541.749579] i915 0000:00:02.0: [drm:intel_psr_post_plane_update [i915]] Enabling PSR2
<7> [541.751138] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:507:eDP-1]
<7> [541.751354] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:150:pipe A]
<7> [544.210541] i915 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turning VDD off
<7> [544.211151] i915 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [546.251416] i915 0000:00:02.0: [drm:drm_dp_dpcd_access [drm_display_helper]] AUX B/DDI B/PHY B: Too many retries, giving up. First error: -6
<7> [546.251675] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port D/TC#1: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4
<7> [546.274706] i915 0000:00:02.0: [drm:drm_dp_dpcd_access [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Too many retries, giving up. First error: -6
<7> [546.274915] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port F/TC#3: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4
<7> [546.301645] i915 0000:00:02.0: [drm:drm_dp_dpcd_access [drm_display_helper]] AUX USBC3/DDI TC3/PHY TC3: Too many retries, giving up. First error: -6
<7> [546.301915] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port G/TC#4: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4
<7> [546.324956] i915 0000:00:02.0: [drm:drm_dp_dpcd_access [drm_display_helper]] AUX USBC4/DDI TC4/PHY TC4: Too many retries, giving up. First error: -6
<7> [546.325106] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turning VDD on
<7> [546.325417] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f
<7> [547.266151] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [547.328812] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port G/TC#4: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [547.328912] i915 0000:00:02.0: [drm:intel_tc_port_reset_mode [i915]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [548.835982] i915 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turning VDD off
<7> [548.836534] i915 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [549.266695] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [549.267252] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [549.267793] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02
<7> [552.234583] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]
<7> [552.235017] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [552.235979] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [552.236787] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [552.237434] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [552.237994] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 7483046/8388608 link 498869/524288, found tu 0, data 0/0 link 0/0)
<7> [552.238386] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [552.238757] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [552.239082] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [552.239334] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [552.239650] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [552.239900] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [552.240145] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [552.240359] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [552.240562] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [552.240836] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1801, found 0)
<7> [552.241027] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [552.241160] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [552.241307] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1878, found 0)
<7> [552.241485] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1878, found 0)
<7> [552.241785] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [552.241966] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [552.242158] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [552.242349] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [552.242490] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [552.242632] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [552.242775] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [552.242909] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1801, found 0)
<7> [552.243037] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [552.243213] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [552.243371] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1878, found 0)
<7> [552.243516] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1878, found 0)
<7> [552.243662] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [552.243790] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [552.243918] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [552.244048] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no)
<7> [552.244177] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [552.244324] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 513820, found 0)
<7> [552.244462] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 513820, found 0)
<7> [552.244594] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 540000, found 0)
<7> [552.244735] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in set_context_latency (expected 1, found 0)
<7> [552.244862] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset
<7> [552.244991] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:150:pipe A] releasing DPLL 0
<7> [552.245165] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [552.245343] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:150:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [552.245539] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:34:plane 1A] ddb ( 0 - 4001) -> ( 0 - 0), size 4001 -> 0
<7> [552.245686] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:144:cursor A] ddb (4001 - 4096) -> ( 0 - 0), size 95 -> 0
<7> [552.245829] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [552.245979] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] lines 4, 16, 16, 19, 19, 28, 0, 0, 0, 4, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [552.246122] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] blocks 92, 365, 365, 434, 434, 638, 0, 0, 197, 92, 197 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [552.246261] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] min_ddb 183, 456, 456, 547, 547, 729, 0, 0, 198, 183, 198 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [552.246455] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:150:pipe A] data rate 0 num active planes 0
<7> [552.246591] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 28913 required 0 qgv_peak_bw: 51200
<7> [552.246723] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 1: max bw 38000 required 0 qgv_peak_bw: 51200
<7> [552.246855] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 51200
<7> [552.246986] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 51200
<7> [552.247117] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] Matching peaks QGV bw: 51200 for required data rate: 0
<7> [552.247258] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:150:pipe A] min cdclk: 256910 kHz -> 0 kHz
<7> [552.247409] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 32114 kHz -> 0 kHz
<7> [552.247539] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Can change cdclk via squashing
<7> [552.247665] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 172800 kHz, actual 172800 kHz
<7> [552.247790] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [552.247946] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:150:pipe A] enable: no [modeset]
<7> [552.248082] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:plane 1A] fb: [NOFB], visible: no
<7> [552.248229] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:64:plane 2A] fb: [NOFB], visible: no
<7> [552.248369] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:94:plane 3A] fb: [NOFB], visible: no
<7> [552.248528] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:124:plane 4A] fb: [NOFB], visible: no
<7> [552.248681] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:134:plane 5A] fb: [NOFB], visible: no
<7> [552.248815] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:144:cursor A] fb: [NOFB], visible: no
<7> [552.249006] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [552.249781] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 02 to 00
<7> [552.250071] i915 0000:00:02.0: [drm:intel_psr_disable_locked [i915]] Disabling PSR2
<7> [552.250372] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turning VDD on
<7> [552.250602] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f
<7> [552.251449] i915 0000:00:02.0: [drm:intel_edp_backlight_off [i915]]
<7> [552.458299] i915 0000:00:02.0: [drm:intel_backlight_set_pwm_level [i915]] [CONNECTOR:507:eDP-1] set backlight PWM = 0
<7> [552.459349] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [552.462475] i915 0000:00:02.0: [drm:intel_pps_off_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turn panel power off
<7> [552.462839] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x00000089, pins 0x00000010, long 0x00000000
<7> [552.463097] i915 0000:00:02.0: [drm:intel_pps_off_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [552.463404] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:506:DDI A/PHY A] - short
<7> [552.463670] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [552.515812] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x0000008a, pins 0x00000010, long 0x00000010
<7> [552.516391] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:506:DDI A/PHY A] - long
<7> [552.516892] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [552.522470] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete
<7> [552.523008] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:150:pipe A]
<7> [552.523152] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring short hpd on eDP [ENCODER:506:DDI A/PHY A]
<7> [552.523680] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP [ENCODER:506:DDI A/PHY A]
<7> [552.524709] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0
<7> [552.525080] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling AUX_A
<7> [552.525462] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:506:DDI A/PHY A]
<7> [552.525740] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:515:DDI B/PHY B]
<7> [552.525941] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:517:DP-MST A]
<7> [552.526094] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:518:DP-MST B]
<7> [552.526281] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DP-MST C]
<7> [552.526440] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DP-MST D]
<7> [552.526587] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:533:DDI TC1/PHY TC1]
<7> [552.526735] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DP-MST A]
<7> [552.526882] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:536:DP-MST B]
<7> [552.527028] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST C]
<7> [552.527295] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST D]
<7> [552.527580] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:542:DDI TC2/PHY TC2]
<7> [552.527833] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:546:DDI TC3/PHY TC3]
<7> [552.527993] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:548:DP-MST A]
<7> [552.528145] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST B]
<7> [552.528279] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST C]
<7> [552.528407] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST D]
<7> [552.528533] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:555:DDI TC4/PHY TC4]
<7> [552.528658] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:557:DP-MST A]
<7> [552.528781] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:558:DP-MST B]
<7> [552.528908] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:559:DP-MST C]
<7> [552.529035] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:560:DP-MST D]
<7> [552.529179] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:507:eDP-1]
<7> [552.529372] i915 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [i915]] Updating dbuf ratio to 2 (mbus joined: no)
<7> [552.529519] i915 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [i915]] Changing mbus joined: yes -> no (pipe: *)
<7> [552.529651] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [552.529888] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_A
<7> [552.530032] i915 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [i915]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [552.530247] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:150:pipe A]
<7> [552.530463] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Post changing CDCLK to 172800 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [552.530702] i915 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=432
<7> [552.531151] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]
<7> [552.531323] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:386:pipe C]
<7> [552.531434] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:504:pipe D]
<7> [552.531535] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]
<7> [552.531560] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:507:eDP-1]
<7> [552.531611] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:507:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [552.531761] i915 0000:00:02.0: [drm:intel_dp_compute_config_limits [i915]] [ENCODER:506:DDI A/PHY A][CRTC:150:pipe A] DP link limits: pixel clock 513820 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000
<7> [552.531887] i915 0000:00:02.0: [drm:intel_dp_compute_link_config [i915]] DP lane count 4 clock 540000 bpp input 30 compressed 0.0000 HDR no link rate required 1926825 available 2160000
<7> [552.532017] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [552.532177] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:506:DDI A/PHY A] [CRTC:150:pipe A]
<7> [552.532300] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [552.532436] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [552.532570] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [552.532702] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [552.532835] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 7483046/8388608 link 498869/524288)
<7> [552.532968] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [552.533114] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [552.533248] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [552.533376] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [552.533510] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [552.533719] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [552.533920] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [552.534150] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [552.534354] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [552.534495] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1801)
<7> [552.534636] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [552.534775] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [552.534912] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1878)
<7> [552.535056] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1878)
<7> [552.535192] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [552.535326] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [552.535459] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [552.535591] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [552.535723] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [552.535855] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [552.535987] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [552.536143] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1801)
<7> [552.536277] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [552.536409] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [552.536541] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1878)
<7> [552.536673] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1878)
<7> [552.536839] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [552.537062] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [552.537276] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [552.537476] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in enhanced_framing (expected no, found yes)
<7> [552.537641] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [552.537787] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 513820)
<7> [552.537926] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 513820)
<7> [552.538084] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 540000)
<7> [552.538222] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in set_context_latency (expected 0, found 1)
<7> [552.538359] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset
<7> [552.538525] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [552.538656] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1
<7> [552.538812] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4001), size 0 -> 4001
<7> [552.538939] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4001 - 4096), size 0 -> 95
<7> [552.539098] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [552.539224] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 16, 16, 19, 19, 28, 0, 0, 0, 4, 0
<7> [552.539350] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 365, 365, 434, 434, 638, 0, 0, 197, 92, 197
<7> [552.539475] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:34:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 547, 547, 729, 0, 0, 198, 183, 198
<7> [552.539611] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:150:pipe A] data rate 2055280 num active planes 1
<7> [552.539751] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 28913 required 2159 qgv_peak_bw: 51200
<7> [552.539894] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 1: max bw 38000 required 2159 qgv_peak_bw: 51200
<7> [552.540233] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 2: max bw 38000 required 2159 qgv_peak_bw: 51200
<7> [552.540431] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 3: max bw 38000 required 2159 qgv_peak_bw: 51200
<7> [552.540630] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] Matching peaks QGV bw: 51200 for required data rate: 2159
<7> [552.540785] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 256910 kHz
<7> [552.540945] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 32114 kHz
<7> [552.541110] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Can change cdclk via squashing
<7> [552.541246] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 307200 kHz, actual 307200 kHz
<7> [552.541379] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [552.541530] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:150:pipe A] allocated DPLL 0
<7> [552.541668] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:150:pipe A] reserving DPLL 0
<7> [552.541810] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:150:pipe A] enable: yes [modeset]
<7> [552.541948] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [552.542100] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [552.542236] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [552.542374] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [552.542511] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [552.542648] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [552.542782] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dp m_n: lanes: 4; data_m: 7483046, data_n: 8388608, link_m: 498869, link_n: 524288, tu: 64
<7> [552.542915] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [552.543108] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fec: disabled, enhanced framing: enabled
<7> [552.543310] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sdp split: disabled
<7> [552.543506] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [552.543706] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] minimum HBlank: 0
<7> [552.543868] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [552.544021] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] DP SDP: VSC, revision 4, length 14
<7> [552.544159] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pixelformat: RGB
<7> [552.544296] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] colorimetry: sRGB
<7> [552.544431] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] bpc: 0
<7> [552.544564] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dynamic range: VESA range
<7> [552.544696] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] content type: Not defined
<7> [552.544830] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1
<7> [552.544974] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 1
<7> [552.545110] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1878, vmax: 1878, flipline: 1878, pipeline full: 0, guardband: 76 vsync start: 75, vsync end: 69
<7> [552.545244] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1878, vmax vtotal: 1878
<7> [552.545375] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [552.545507] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa
<7> [552.545639] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa
<7> [552.545771] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=513820, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1801-1878 vs=1803-1809 vt=1878, flags=0xa
<7> [552.545905] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x40 0xa
<7> [552.546069] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=513820, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1801-1878 vs=1803-1809 vt=1878, flags=0xa
<7> [552.546266] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 540000, pipe src: 2880x1800+0+0, pixel rate 513820, min cdclk 256910
<7> [552.546461] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 48, ips linetime: 0
<7> [552.546664] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [552.546845] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [552.546996] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [552.547133] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no
<7> [552.547270] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] c10pll_hw_state: fracen: yes,
<7> [552.547403] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] quot: 40960, rem: 0, den: 1,
<7> [552.547539] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] multiplier: 140, tx_clk_div: 0.
<7> [552.547676] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] c10pll_rawhw_state:
<7> [552.547811] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] tx: 0x10, cmn: 0x21
<7> [552.547963] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[0] = 0xf4, pll[1] = 0x0, pll[2] = 0xf8, pll[3] = 0x0
<7> [552.548101] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [552.548237] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [552.548373] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[12] = 0xa0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x0
<7> [552.548505] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[16] = 0x84, pll[17] = 0x4f, pll[18] = 0xe5, pll[19] = 0x23
<7> [552.548638] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [552.548771] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [552.548902] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [552.549156] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [552.549376] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [552.549213] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [552.549572] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [552.549720] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [552.549857] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [552.549773] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [552.550022] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [552.550156] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [552.550295] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [552.550435] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [552.550323] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02
<7> [552.550573] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [552.550709] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:plane 1A] fb: [FB:565] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [552.550851] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [552.551007] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [552.550855] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on
<7> [552.551149] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:64:plane 2A] fb: [NOFB], visible: no
<7> [552.551286] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:94:plane 3A] fb: [NOFB], visible: no
<7> [552.551421] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:124:plane 4A] fb: [NOFB], visible: no
<7> [552.551554] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:134:plane 5A] fb: [NOFB], visible: no
<7> [552.551688] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:144:cursor A] fb: [NOFB], visible: no
<7> [552.551918] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on
<7> [552.552128] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [552.552480] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 02 to 00
<7> [552.552785] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [552.553037] i915 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [i915]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)
<7> [552.553199] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 307200 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [552.553377] i915 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=768
<7> [552.553517] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:506:DDI A/PHY A]
<7> [552.553653] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:515:DDI B/PHY B]
<7> [552.553789] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:517:DP-MST A]
<7> [552.553935] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:518:DP-MST B]
<7> [552.554064] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DP-MST C]
<7> [552.554195] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DP-MST D]
<7> [552.554324] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:533:DDI TC1/PHY TC1]
<7> [552.554451] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DP-MST A]
<7> [552.554580] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:536:DP-MST B]
<7> [552.554707] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST C]
<7> [552.554842] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST D]
<7> [552.555007] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:542:DDI TC2/PHY TC2]
<7> [552.555172] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:546:DDI TC3/PHY TC3]
<7> [552.555363] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:548:DP-MST A]
<7> [552.555553] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST B]
<7> [552.555744] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST C]
<7> [552.555935] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST D]
<7> [552.556072] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:555:DDI TC4/PHY TC4]
<7> [552.556201] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:557:DP-MST A]
<7> [552.556329] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:558:DP-MST B]
<7> [552.556458] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:559:DP-MST C]
<7> [552.556588] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:560:DP-MST D]
<7> [552.556747] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xf
<7> [552.556997] i915 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [i915]] Changing mbus joined: no -> yes (pipe: *)
<7> [552.557139] i915 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [i915]] Updating dbuf ratio to 4 (mbus joined: yes)
<7> [552.557347] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling AUX_A
<7> [552.558696] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:150:pipe A]
<7> [552.558849] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0
<7> [552.560630] i915 0000:00:02.0: [drm:intel_pps_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turn panel power on
<7> [552.560860] i915 0000:00:02.0: [drm:wait_panel_power_cycle [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 wait for panel power cycle (462 ms remaining)
<7> [553.020692] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [553.041653] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete
<7> [553.042253] i915 0000:00:02.0: [drm:intel_pps_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 wait for panel power on
<7> [553.042768] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [553.074894] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x0000008a, pins 0x00000010, long 0x00000010
<7> [553.075456] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:506:DDI A/PHY A] - long
<7> [553.075963] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [553.076592] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP [ENCODER:506:DDI A/PHY A]
<7> [553.247210] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete
<7> [553.248174] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turning VDD on
<7> [553.248896] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [553.252355] i915 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 14 c4 41 00 00 01 c0 02 00 00 00 00 0b 80
<7> [553.253585] i915 0000:00:02.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [553.254188] i915 0000:00:02.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 07
<7> [553.255369] i915 0000:00:02.0: [drm:intel_dp_set_signal_levels [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [553.256204] i915 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [553.257076] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Clock recovery OK
<7> [553.257200] i915 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Using DP training pattern TPS3
<7> [553.258547] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [553.258671] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:507:eDP-1][ENCODER:506:DDI A/PHY A][DPRX] Link Training passed at link rate = 540000, lane count = 4
<7> [553.259265] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [553.259525] i915 0000:00:02.0: [drm:intel_edp_backlight_on [i915]]
<7> [553.259651] i915 0000:00:02.0: [drm:intel_backlight_enable [i915]] pipe A
<7> [553.259846] i915 0000:00:02.0: [drm:intel_backlight_set_pwm_level [i915]] [CONNECTOR:507:eDP-1] set backlight PWM = 4518
<7> [553.270679] i915 0000:00:02.0: [drm:intel_psr_post_plane_update [i915]] Enabling PSR2
<7> [553.272925] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:507:eDP-1]
<7> [553.273619] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:150:pipe A]
<7> [555.796745] i915 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 turning VDD off
<7> [555.797311] i915 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [i915]] [ENCODER:506:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [560.943898] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [560.944559] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [560.945105] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02
<6> [561.332637] [IGT] kms_flip: finished subtest A-eDP1, FAIL
Created at 2026-03-03 09:02:55