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

Result: Fail

i915_display_info14 igt_runner14 results14.json results14-xe-load.json guc_logs14.tar i915_display_info_post_exec14 boot14 dmesg14

DetailValue
Duration 26.18 seconds
Hostname
shard-lnl-6
Igt-Version
IGT-Version: 2.4-g63a08403d (x86_64) (Linux: 7.0.0-lgci-xe-xe-pw-164944v1-debug+ x86_64)
Out
Using IGT_SRANDOM=1776296254 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: plain-flip-ts-check
Starting dynamic subtest: A-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Expected frametime: 16664us; measured 16542.0us +- 8.157us accuracy 0.15%
vblank interval differs from modeline! expected 16664.0us, measured 16542us +- 8.157us, difference 122.0us (15.0 sigma)
Event flip: expected 605, counted 603, passrate = 81.43%, encoder type 2
Expected frametime: 16664us; measured 16646.6us +- 3.741us accuracy 0.07%
vblank interval differs from modeline! expected 16664.0us, measured 16647us +- 3.741us, difference 17.4us (4.7 sigma)
Event flip: expected 601, counted 598, passrate = 29.43%, encoder type 2
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:1071 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (26.183s)
Err
Starting subtest: plain-flip-ts-check
Starting dynamic subtest: A-eDP1
(kms_flip:2387) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1722:
(kms_flip:2387) CRITICAL: Failed assertion: !retried
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.460632
last_received_ts = 89.460052
last_seq = 1735
current_ts = 89.477364
current_received_ts = 89.476768
current_seq = 1736
count = 508
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.460632/1735, current 89.477364/1736: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.460632/1735, current 89.477364/1736: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.477364
last_received_ts = 89.476768
last_seq = 1736
current_ts = 89.494102
current_received_ts = 89.493484
current_seq = 1737
count = 509
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.477364/1736, current 89.494102/1737: elapsed=16739.0us expected=16646.6us +- 83.2us, error 0.6%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.477364/1736, current 89.494102/1737: elapsed=16739.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.494102
last_received_ts = 89.493484
last_seq = 1737
current_ts = 89.510834
current_received_ts = 89.510262
current_seq = 1738
count = 510
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.494102/1737, current 89.510834/1738: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.494102/1737, current 89.510834/1738: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.510834
last_received_ts = 89.510262
last_seq = 1738
current_ts = 89.527573
current_received_ts = 89.526855
current_seq = 1739
count = 511
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.510834/1738, current 89.527573/1739: elapsed=16735.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.510834/1738, current 89.527573/1739: elapsed=16735.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.527573
last_received_ts = 89.526855
last_seq = 1739
current_ts = 89.544296
current_received_ts = 89.543579
current_seq = 1740
count = 512
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.527573/1739, current 89.544296/1740: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.527573/1739, current 89.544296/1740: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.544296
last_received_ts = 89.543579
last_seq = 1740
current_ts = 89.561035
current_received_ts = 89.560249
current_seq = 1741
count = 513
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.544296/1740, current 89.561035/1741: elapsed=16737.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.544296/1740, current 89.561035/1741: elapsed=16737.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.561035
last_received_ts = 89.560249
last_seq = 1741
current_ts = 89.577766
current_received_ts = 89.577072
current_seq = 1742
count = 514
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.561035/1741, current 89.577766/1742: elapsed=16732.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.561035/1741, current 89.577766/1742: elapsed=16732.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.577766
last_received_ts = 89.577072
last_seq = 1742
current_ts = 89.594505
current_received_ts = 89.593811
current_seq = 1743
count = 515
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.577766/1742, current 89.594505/1743: elapsed=16735.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.577766/1742, current 89.594505/1743: elapsed=16735.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.594505
last_received_ts = 89.593811
last_seq = 1743
current_ts = 89.611237
current_received_ts = 89.610641
current_seq = 1744
count = 516
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.594505/1743, current 89.611237/1744: elapsed=16733.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.594505/1743, current 89.611237/1744: elapsed=16733.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.611237
last_received_ts = 89.610641
last_seq = 1744
current_ts = 89.627975
current_received_ts = 89.627350
current_seq = 1745
count = 517
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.611237/1744, current 89.627975/1745: elapsed=16742.0us expected=16646.6us +- 83.2us, error 0.6%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.611237/1744, current 89.627975/1745: elapsed=16742.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.627975
last_received_ts = 89.627350
last_seq = 1745
current_ts = 89.644707
current_received_ts = 89.644119
current_seq = 1746
count = 518
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.627975/1745, current 89.644707/1746: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.627975/1745, current 89.644707/1746: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.644707
last_received_ts = 89.644119
last_seq = 1746
current_ts = 89.661438
current_received_ts = 89.660851
current_seq = 1747
count = 519
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.644707/1746, current 89.661438/1747: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.644707/1746, current 89.661438/1747: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.661438
last_received_ts = 89.660851
last_seq = 1747
current_ts = 89.678177
current_received_ts = 89.677574
current_seq = 1748
count = 520
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.661438/1747, current 89.678177/1748: elapsed=16735.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.661438/1747, current 89.678177/1748: elapsed=16735.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.678177
last_received_ts = 89.677574
last_seq = 1748
current_ts = 89.694916
current_received_ts = 89.694290
current_seq = 1749
count = 521
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.678177/1748, current 89.694916/1749: elapsed=16737.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.678177/1748, current 89.694916/1749: elapsed=16737.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.694916
last_received_ts = 89.694290
last_seq = 1749
current_ts = 89.711647
current_received_ts = 89.711060
current_seq = 1750
count = 522
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.694916/1749, current 89.711647/1750: elapsed=16732.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.694916/1749, current 89.711647/1750: elapsed=16732.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.711647
last_received_ts = 89.711060
last_seq = 1750
current_ts = 89.728378
current_received_ts = 89.727798
current_seq = 1751
count = 523
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.711647/1750, current 89.728378/1751: elapsed=16735.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.711647/1750, current 89.728378/1751: elapsed=16735.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.728378
last_received_ts = 89.727798
last_seq = 1751
current_ts = 89.745110
current_received_ts = 89.744507
current_seq = 1752
count = 524
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.728378/1751, current 89.745110/1752: elapsed=16733.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.728378/1751, current 89.745110/1752: elapsed=16733.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.745110
last_received_ts = 89.744507
last_seq = 1752
current_ts = 89.761848
current_received_ts = 89.761253
current_seq = 1753
count = 525
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.745110/1752, current 89.761848/1753: elapsed=16734.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.745110/1752, current 89.761848/1753: elapsed=16734.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.761848
last_received_ts = 89.761253
last_seq = 1753
current_ts = 89.778587
current_received_ts = 89.777992
current_seq = 1754
count = 526
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.761848/1753, current 89.778587/1754: elapsed=16741.0us expected=16646.6us +- 83.2us, error 0.6%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.761848/1753, current 89.778587/1754: elapsed=16741.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.778587
last_received_ts = 89.777992
last_seq = 1754
current_ts = 89.795319
current_received_ts = 89.794716
current_seq = 1755
count = 527
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.778587/1754, current 89.795319/1755: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.778587/1754, current 89.795319/1755: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.795319
last_received_ts = 89.794716
last_seq = 1755
current_ts = 89.812050
current_received_ts = 89.811409
current_seq = 1756
count = 528
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.795319/1755, current 89.812050/1756: elapsed=16735.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.795319/1755, current 89.812050/1756: elapsed=16735.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.812050
last_received_ts = 89.811409
last_seq = 1756
current_ts = 89.828789
current_received_ts = 89.828186
current_seq = 1757
count = 529
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.812050/1756, current 89.828789/1757: elapsed=16734.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.812050/1756, current 89.828789/1757: elapsed=16734.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.828789
last_received_ts = 89.828186
last_seq = 1757
current_ts = 89.845528
current_received_ts = 89.844933
current_seq = 1758
count = 530
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.828789/1757, current 89.845528/1758: elapsed=16740.0us expected=16646.6us +- 83.2us, error 0.6%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.828789/1757, current 89.845528/1758: elapsed=16740.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.845528
last_received_ts = 89.844933
last_seq = 1758
current_ts = 89.862259
current_received_ts = 89.861656
current_seq = 1759
count = 531
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.845528/1758, current 89.862259/1759: elapsed=16734.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.845528/1758, current 89.862259/1759: elapsed=16734.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.862259
last_received_ts = 89.861656
last_seq = 1759
current_ts = 89.878990
current_received_ts = 89.878380
current_seq = 1760
count = 532
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.862259/1759, current 89.878990/1760: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.862259/1759, current 89.878990/1760: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.878990
last_received_ts = 89.878380
last_seq = 1760
current_ts = 89.895721
current_received_ts = 89.895134
current_seq = 1761
count = 533
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.878990/1760, current 89.895721/1761: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.878990/1760, current 89.895721/1761: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.895721
last_received_ts = 89.895134
last_seq = 1761
current_ts = 89.912460
current_received_ts = 89.911865
current_seq = 1762
count = 534
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.895721/1761, current 89.912460/1762: elapsed=16737.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.895721/1761, current 89.912460/1762: elapsed=16737.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.912460
last_received_ts = 89.911865
last_seq = 1762
current_ts = 89.929199
current_received_ts = 89.928596
current_seq = 1763
count = 535
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.912460/1762, current 89.929199/1763: elapsed=16737.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.912460/1762, current 89.929199/1763: elapsed=16737.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.929199
last_received_ts = 89.928596
last_seq = 1763
current_ts = 89.945930
current_received_ts = 89.945312
current_seq = 1764
count = 536
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.929199/1763, current 89.945930/1764: elapsed=16734.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.929199/1763, current 89.945930/1764: elapsed=16734.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.945930
last_received_ts = 89.945312
last_seq = 1764
current_ts = 89.962662
current_received_ts = 89.962082
current_seq = 1765
count = 537
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.945930/1764, current 89.962662/1765: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.945930/1764, current 89.962662/1765: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.962662
last_received_ts = 89.962082
last_seq = 1765
current_ts = 89.979401
current_received_ts = 89.978790
current_seq = 1766
count = 538
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.962662/1765, current 89.979401/1766: elapsed=16742.0us expected=16646.6us +- 83.2us, error 0.6%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.962662/1765, current 89.979401/1766: elapsed=16742.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.979401
last_received_ts = 89.978790
last_seq = 1766
current_ts = 89.996140
current_received_ts = 89.995522
current_seq = 1767
count = 539
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.979401/1766, current 89.996140/1767: elapsed=16734.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 89.979401/1766, current 89.996140/1767: elapsed=16734.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 89.996140
last_received_ts = 89.995522
last_seq = 1767
current_ts = 90.012863
current_received_ts = 90.012276
current_seq = 1768
count = 540
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 89.996140/1767, current 90.012863/1768: elapsed=16728.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.012863
last_received_ts = 90.012276
last_seq = 1768
current_ts = 90.029594
current_received_ts = 90.029045
current_seq = 1769
count = 541
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.012863/1768, current 90.029594/1769: elapsed=16733.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.012863/1768, current 90.029594/1769: elapsed=16733.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.029594
last_received_ts = 90.029045
last_seq = 1769
current_ts = 90.046333
current_received_ts = 90.045731
current_seq = 1770
count = 542
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.029594/1769, current 90.046333/1770: elapsed=16736.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.029594/1769, current 90.046333/1770: elapsed=16736.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.046333
last_received_ts = 90.045731
last_seq = 1770
current_ts = 90.063072
current_received_ts = 90.062462
current_seq = 1771
count = 543
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.046333/1770, current 90.063072/1771: elapsed=16738.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.046333/1770, current 90.063072/1771: elapsed=16738.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.063072
last_received_ts = 90.062462
last_seq = 1771
current_ts = 90.079803
current_received_ts = 90.079117
current_seq = 1772
count = 544
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.063072/1771, current 90.079803/1772: elapsed=16729.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.079803
last_received_ts = 90.079117
last_seq = 1772
current_ts = 90.096542
current_received_ts = 90.095940
current_seq = 1773
count = 545
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.079803/1772, current 90.096542/1773: elapsed=16739.0us expected=16646.6us +- 83.2us, error 0.6%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.079803/1772, current 90.096542/1773: elapsed=16739.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.096542
last_received_ts = 90.095940
last_seq = 1773
current_ts = 90.113266
current_received_ts = 90.112671
current_seq = 1774
count = 546
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.096542/1773, current 90.113266/1774: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.096542/1773, current 90.113266/1774: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.113266
last_received_ts = 90.112671
last_seq = 1774
current_ts = 90.130013
current_received_ts = 90.129402
current_seq = 1775
count = 547
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.113266/1774, current 90.130013/1775: elapsed=16742.0us expected=16646.6us +- 83.2us, error 0.6%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.113266/1774, current 90.130013/1775: elapsed=16742.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.130013
last_received_ts = 90.129402
last_seq = 1775
current_ts = 90.146744
current_received_ts = 90.146141
current_seq = 1776
count = 548
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.130013/1775, current 90.146744/1776: elapsed=16734.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.130013/1775, current 90.146744/1776: elapsed=16734.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.146744
last_received_ts = 90.146141
last_seq = 1776
current_ts = 90.163475
current_received_ts = 90.162903
current_seq = 1777
count = 549
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.146744/1776, current 90.163475/1777: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.146744/1776, current 90.163475/1777: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.163475
last_received_ts = 90.162903
last_seq = 1777
current_ts = 90.180214
current_received_ts = 90.179619
current_seq = 1778
count = 550
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.163475/1777, current 90.180214/1778: elapsed=16738.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.163475/1777, current 90.180214/1778: elapsed=16738.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.180214
last_received_ts = 90.179619
last_seq = 1778
current_ts = 90.196945
current_received_ts = 90.196335
current_seq = 1779
count = 551
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.180214/1778, current 90.196945/1779: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.180214/1778, current 90.196945/1779: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.196945
last_received_ts = 90.196335
last_seq = 1779
current_ts = 90.213676
current_received_ts = 90.213120
current_seq = 1780
count = 552
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.196945/1779, current 90.213676/1780: elapsed=16736.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.196945/1779, current 90.213676/1780: elapsed=16736.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.213676
last_received_ts = 90.213120
last_seq = 1780
current_ts = 90.230415
current_received_ts = 90.229820
current_seq = 1781
count = 553
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.213676/1780, current 90.230415/1781: elapsed=16737.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.213676/1780, current 90.230415/1781: elapsed=16737.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.230415
last_received_ts = 90.229820
last_seq = 1781
current_ts = 90.247147
current_received_ts = 90.246567
current_seq = 1782
count = 554
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.230415/1781, current 90.247147/1782: elapsed=16733.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.230415/1781, current 90.247147/1782: elapsed=16733.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.247147
last_received_ts = 90.246567
last_seq = 1782
current_ts = 90.263885
current_received_ts = 90.263283
current_seq = 1783
count = 555
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.247147/1782, current 90.263885/1783: elapsed=16735.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.247147/1782, current 90.263885/1783: elapsed=16735.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.263885
last_received_ts = 90.263283
last_seq = 1783
current_ts = 90.280617
current_received_ts = 90.280045
current_seq = 1784
count = 556
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.263885/1783, current 90.280617/1784: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.263885/1783, current 90.280617/1784: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.280617
last_received_ts = 90.280045
last_seq = 1784
current_ts = 90.297348
current_received_ts = 90.296745
current_seq = 1785
count = 557
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.280617/1784, current 90.297348/1785: elapsed=16734.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.280617/1784, current 90.297348/1785: elapsed=16734.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.297348
last_received_ts = 90.296745
last_seq = 1785
current_ts = 90.314087
current_received_ts = 90.313484
current_seq = 1786
count = 558
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.297348/1785, current 90.314087/1786: elapsed=16741.0us expected=16646.6us +- 83.2us, error 0.6%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.297348/1785, current 90.314087/1786: elapsed=16741.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.314087
last_received_ts = 90.313484
last_seq = 1786
current_ts = 90.330818
current_received_ts = 90.330231
current_seq = 1787
count = 559
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.314087/1786, current 90.330818/1787: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.314087/1786, current 90.330818/1787: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.330818
last_received_ts = 90.330231
last_seq = 1787
current_ts = 90.347549
current_received_ts = 90.346954
current_seq = 1788
count = 560
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.330818/1787, current 90.347549/1788: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.330818/1787, current 90.347549/1788: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.347549
last_received_ts = 90.346954
last_seq = 1788
current_ts = 90.364288
current_received_ts = 90.363693
current_seq = 1789
count = 561
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.347549/1788, current 90.364288/1789: elapsed=16737.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.347549/1788, current 90.364288/1789: elapsed=16737.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.364288
last_received_ts = 90.363693
last_seq = 1789
current_ts = 90.381020
current_received_ts = 90.380432
current_seq = 1790
count = 562
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.364288/1789, current 90.381020/1790: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.364288/1789, current 90.381020/1790: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.381020
last_received_ts = 90.380432
last_seq = 1790
current_ts = 90.397758
current_received_ts = 90.397163
current_seq = 1791
count = 563
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.381020/1790, current 90.397758/1791: elapsed=16736.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.381020/1790, current 90.397758/1791: elapsed=16736.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.397758
last_received_ts = 90.397163
last_seq = 1791
current_ts = 90.414490
current_received_ts = 90.413895
current_seq = 1792
count = 564
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.397758/1791, current 90.414490/1792: elapsed=16735.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.397758/1791, current 90.414490/1792: elapsed=16735.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.414490
last_received_ts = 90.413895
last_seq = 1792
current_ts = 90.431221
current_received_ts = 90.430618
current_seq = 1793
count = 565
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.414490/1792, current 90.431221/1793: elapsed=16727.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.431221
last_received_ts = 90.430618
last_seq = 1793
current_ts = 90.447945
current_received_ts = 90.447334
current_seq = 1794
count = 566
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.431221/1793, current 90.447945/1794: elapsed=16726.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.447945
last_received_ts = 90.447334
last_seq = 1794
current_ts = 90.464668
current_received_ts = 90.464050
current_seq = 1795
count = 567
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.447945/1794, current 90.464668/1795: elapsed=16728.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.464668
last_received_ts = 90.464050
last_seq = 1795
current_ts = 90.481400
current_received_ts = 90.480812
current_seq = 1796
count = 568
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.464668/1795, current 90.481400/1796: elapsed=16728.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.481400
last_received_ts = 90.480812
last_seq = 1796
current_ts = 90.498123
current_received_ts = 90.497528
current_seq = 1797
count = 569
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.481400/1796, current 90.498123/1797: elapsed=16726.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.498123
last_received_ts = 90.497528
last_seq = 1797
current_ts = 90.514854
current_received_ts = 90.514259
current_seq = 1798
count = 570
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.498123/1797, current 90.514854/1798: elapsed=16727.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.514854
last_received_ts = 90.514259
last_seq = 1798
current_ts = 90.531578
current_received_ts = 90.530968
current_seq = 1799
count = 571
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.514854/1798, current 90.531578/1799: elapsed=16722.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.531578
last_received_ts = 90.530968
last_seq = 1799
current_ts = 90.548302
current_received_ts = 90.547714
current_seq = 1800
count = 572
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.531578/1799, current 90.548302/1800: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.531578/1799, current 90.548302/1800: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.548302
last_received_ts = 90.547714
last_seq = 1800
current_ts = 90.565025
current_received_ts = 90.564415
current_seq = 1801
count = 573
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.548302/1800, current 90.565025/1801: elapsed=16722.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.565025
last_received_ts = 90.564415
last_seq = 1801
current_ts = 90.581757
current_received_ts = 90.581169
current_seq = 1802
count = 574
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.565025/1801, current 90.581757/1802: elapsed=16728.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.581757
last_received_ts = 90.581169
last_seq = 1802
current_ts = 90.598488
current_received_ts = 90.597893
current_seq = 1803
count = 575
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.581757/1802, current 90.598488/1803: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.581757/1802, current 90.598488/1803: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.598488
last_received_ts = 90.597893
last_seq = 1803
current_ts = 90.615211
current_received_ts = 90.614609
current_seq = 1804
count = 576
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.598488/1803, current 90.615211/1804: elapsed=16724.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.615211
last_received_ts = 90.614609
last_seq = 1804
current_ts = 90.631943
current_received_ts = 90.631310
current_seq = 1805
count = 577
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.615211/1804, current 90.631943/1805: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.615211/1804, current 90.631943/1805: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.631943
last_received_ts = 90.631310
last_seq = 1805
current_ts = 90.648666
current_received_ts = 90.648071
current_seq = 1806
count = 578
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.631943/1805, current 90.648666/1806: elapsed=16726.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.648666
last_received_ts = 90.648071
last_seq = 1806
current_ts = 90.665382
current_received_ts = 90.664787
current_seq = 1807
count = 579
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.648666/1806, current 90.665382/1807: elapsed=16720.0us expected=16646.6us +- 83.2us, error 0.4%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.665382
last_received_ts = 90.664787
last_seq = 1807
current_ts = 90.682121
current_received_ts = 90.681511
current_seq = 1808
count = 580
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.665382/1807, current 90.682121/1808: elapsed=16733.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.665382/1807, current 90.682121/1808: elapsed=16733.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.682121
last_received_ts = 90.681511
last_seq = 1808
current_ts = 90.698845
current_received_ts = 90.698242
current_seq = 1809
count = 581
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.682121/1808, current 90.698845/1809: elapsed=16727.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.698845
last_received_ts = 90.698242
last_seq = 1809
current_ts = 90.715569
current_received_ts = 90.714989
current_seq = 1810
count = 582
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.698845/1809, current 90.715569/1810: elapsed=16724.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.715569
last_received_ts = 90.714989
last_seq = 1810
current_ts = 90.732292
current_received_ts = 90.731712
current_seq = 1811
count = 583
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.715569/1810, current 90.732292/1811: elapsed=16726.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.732292
last_received_ts = 90.731712
last_seq = 1811
current_ts = 90.749023
current_received_ts = 90.748421
current_seq = 1812
count = 584
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.732292/1811, current 90.749023/1812: elapsed=16731.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.732292/1811, current 90.749023/1812: elapsed=16731.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.749023
last_received_ts = 90.748421
last_seq = 1812
current_ts = 90.765747
current_received_ts = 90.765160
current_seq = 1813
count = 585
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.749023/1812, current 90.765747/1813: elapsed=16721.0us expected=16646.6us +- 83.2us, error 0.4%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.765747
last_received_ts = 90.765160
last_seq = 1813
current_ts = 90.782471
current_received_ts = 90.781876
current_seq = 1814
count = 586
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.765747/1813, current 90.782471/1814: elapsed=16727.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.782471
last_received_ts = 90.781876
last_seq = 1814
current_ts = 90.799202
current_received_ts = 90.798607
current_seq = 1815
count = 587
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.782471/1814, current 90.799202/1815: elapsed=16728.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.799202
last_received_ts = 90.798607
last_seq = 1815
current_ts = 90.815933
current_received_ts = 90.815331
current_seq = 1816
count = 588
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.799202/1815, current 90.815933/1816: elapsed=16728.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.815933
last_received_ts = 90.815331
last_seq = 1816
current_ts = 90.832657
current_received_ts = 90.832085
current_seq = 1817
count = 589
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.815933/1816, current 90.832657/1817: elapsed=16726.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.832657
last_received_ts = 90.832085
last_seq = 1817
current_ts = 90.849380
current_received_ts = 90.848801
current_seq = 1818
count = 590
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.832657/1817, current 90.849380/1818: elapsed=16728.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.849380
last_received_ts = 90.848801
last_seq = 1818
current_ts = 90.866112
current_received_ts = 90.865494
current_seq = 1819
count = 591
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.849380/1818, current 90.866112/1819: elapsed=16725.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.866112
last_received_ts = 90.865494
last_seq = 1819
current_ts = 90.882835
current_received_ts = 90.882256
current_seq = 1820
count = 592
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.866112/1819, current 90.882835/1820: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.866112/1819, current 90.882835/1820: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.882835
last_received_ts = 90.882256
last_seq = 1820
current_ts = 90.899559
current_received_ts = 90.898964
current_seq = 1821
count = 593
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.882835/1820, current 90.899559/1821: elapsed=16719.0us expected=16646.6us +- 83.2us, error 0.4%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.899559
last_received_ts = 90.898964
last_seq = 1821
current_ts = 90.916290
current_received_ts = 90.915688
current_seq = 1822
count = 594
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.899559/1821, current 90.916290/1822: elapsed=16730.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: inconsistent flip ts/seq: last 90.899559/1821, current 90.916290/1822: elapsed=16730.0us expected=16646.6us
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.916290
last_received_ts = 90.915688
last_seq = 1822
current_ts = 90.933014
current_received_ts = 90.932419
current_seq = 1823
count = 595
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.916290/1822, current 90.933014/1823: elapsed=16724.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.933014
last_received_ts = 90.932419
last_seq = 1823
current_ts = 90.949738
current_received_ts = 90.949165
current_seq = 1824
count = 596
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.933014/1823, current 90.949738/1824: elapsed=16729.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) DEBUG: name = flip
last_ts = 90.949738
last_received_ts = 90.949165
last_seq = 1824
current_ts = 90.966469
current_received_ts = 90.965874
current_seq = 1825
count = 597
seq_step = 1
(kms_flip:2387) DEBUG: flip ts/seq: last 90.949738/1824, current 90.966469/1825: elapsed=16725.0us expected=16646.6us +- 83.2us, error 0.5%
(kms_flip:2387) INFO: Event flip: expected 601, counted 598, passrate = 29.43%, encoder type 2
(kms_flip:2387) DEBUG: dropped frames, expected 601, counted 598, passrate = 29.43%, encoder type 2
(kms_flip:2387) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1722:
(kms_flip:2387) CRITICAL: Failed assertion: !retried
(kms_flip:2387) igt_core-INFO: Stack trace:
(kms_flip:2387) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2387) igt_core-INFO:   #1 ../tests/kms_flip.c:1071 run_test_on_crtc_set()
(kms_flip:2387) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2387) igt_core-INFO:   #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
(kms_flip:2387) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2387) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2387) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2387) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (26.183s)
Dmesg
<6> [65.533428] Console: switching to colour dummy device 80x25
<6> [65.533568] [IGT] kms_flip: executing
<7> [65.539161] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]
<7> [65.539170] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1]
<7> [65.539321] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected
<7> [65.539550] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2]
<7> [65.539552] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2]
<7> [65.539670] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected
<7> [65.539949] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3]
<7> [65.539952] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3]
<7> [65.540080] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected
<7> [65.540320] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1]
<7> [65.540323] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:393:eDP-1]
<7> [65.540926] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00
<7> [65.541262] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000
<7> [65.541374] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000
<7> [65.541485] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000
<7> [65.541599] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz
<5> [65.541603] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [65.541605] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [65.541606] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] DisplayID extension version 0x13, primary use 0x00
<7> [65.541607] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc.
<5> [65.541609] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [65.541610] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD monitor
<5> [65.541612] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [65.541613] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD size 20, SAD count 0
<5> [65.541615] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [65.541625] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] VRR capable: yes
<7> [65.541715] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps
<7> [65.541823] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no
<5> [65.542155] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [65.542157] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<5> [65.542159] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)
<7> [65.542204] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] probed modes:
<7> [65.542208] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [65.542212] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa
<7> [65.542224] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]
<7> [65.542227] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1]
<7> [65.542362] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected
<7> [65.542372] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2]
<7> [65.542375] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2]
<7> [65.542491] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected
<7> [65.542498] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3]
<7> [65.542501] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3]
<7> [65.542618] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected
<6> [65.543071] [IGT] kms_flip: starting subtest plain-flip-ts-check
<6> [65.544330] [IGT] kms_flip: starting dynamic subtest A-eDP1
<7> [65.549725] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430]
<7> [65.554249] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432]
<7> [65.646496] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [65.647407] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [65.647715] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [65.647935] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [65.648153] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [65.648360] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0)
<7> [65.648557] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [65.648806] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [65.648991] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [65.649166] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [65.649334] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [65.649497] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [65.649693] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [65.649867] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [65.650019] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [65.650170] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [65.650335] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [65.650498] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [65.650664] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [65.650823] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [65.650957] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [65.651087] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [65.651225] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [65.651351] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [65.651476] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [65.651600] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [65.651759] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [65.651898] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [65.652017] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [65.652148] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [65.652279] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [65.652398] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [65.652510] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [65.652617] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [65.652746] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [65.652854] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [65.652959] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [65.653061] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [65.653162] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [65.653265] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [65.653374] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0
<7> [65.653554] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [65.653641] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [65.653768] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0
<7> [65.653846] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0
<7> [65.653921] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [65.653994] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [65.654065] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [65.654137] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [65.654237] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0
<7> [65.654346] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [65.654455] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [65.654562] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [65.654669] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [65.654795] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [65.654902] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz
<7> [65.655023] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz
<7> [65.655123] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [65.655226] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [65.655325] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [65.655451] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]
<7> [65.655543] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [65.655630] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [65.655724] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [65.655829] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [65.655931] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [65.656026] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [65.656210] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [65.656940] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [65.657096] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2
<7> [65.658508] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [65.658630] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [65.866677] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [65.867282] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [65.876209] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [65.876667] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [65.877073] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [65.929226] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [65.929580] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [65.938087] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [65.938725] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]
<7> [65.938757] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [65.940399] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [65.941585] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [65.942339] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [65.942714] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [65.943017] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [65.943345] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [65.943734] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [65.944018] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [65.944385] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [65.944673] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [65.944944] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [65.945217] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [65.945574] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [65.945921] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [65.946272] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [65.946540] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [65.947019] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [65.947313] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [65.947614] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [65.948113] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [65.948509] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [65.948952] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [65.949320] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [65.949761] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [65.950014] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [65.951222] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [65.951603] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [65.951855] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [65.951901] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [65.952030] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [65.952306] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000
<7> [65.952529] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [65.952767] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [65.952972] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]
<7> [65.953182] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [65.953415] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [65.953615] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [65.953828] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [65.954009] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)
<7> [65.954181] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [65.954364] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [65.954529] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [65.954686] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [65.954856] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [65.955006] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [65.955148] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [65.955288] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [65.955463] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [65.955598] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [65.955747] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [65.955897] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [65.956021] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [65.956159] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [65.956301] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [65.956452] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [65.956568] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [65.956680] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [65.956806] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [65.956932] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [65.957050] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [65.957165] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [65.957272] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [65.957388] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [65.957493] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [65.957596] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [65.957695] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [65.957801] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [65.957902] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [65.957996] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [65.958088] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [65.958177] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [65.958266] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [65.958370] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [65.958521] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [65.958607] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1
<7> [65.958701] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [65.958769] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [65.958830] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [65.958891] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0
<7> [65.958952] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197
<7> [65.959011] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198
<7> [65.959083] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1
<7> [65.959174] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [65.959262] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [65.959354] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [65.959458] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [65.959562] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [65.959661] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [65.959763] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz
<7> [65.959859] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [65.959945] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [65.960029] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [65.960124] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0
<7> [65.960200] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0
<7> [65.960279] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [65.960397] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [65.960506] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [65.960611] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [65.960703] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [65.960784] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [65.960863] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [65.960940] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64
<7> [65.961018] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [65.961094] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [65.961170] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [65.961249] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [65.961332] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [65.961448] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [65.961546] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [65.961646] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [65.961729] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [65.961810] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [65.961891] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [65.961970] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [65.962044] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [65.962116] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [65.962189] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97
<7> [65.962263] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906
<7> [65.962336] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [65.962440] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [65.962537] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [65.962632] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa
<7> [65.962715] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa
<7> [65.962794] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa
<7> [65.962874] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0
<7> [65.962952] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [65.963023] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [65.963096] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [65.963168] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [65.963241] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [65.963312] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [65.963406] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no
<7> [65.963505] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [65.963602] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [65.963708] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [65.963801] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [65.963847] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [65.963893] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [65.963943] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [65.963976] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [65.964036] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [65.964059] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [65.964140] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [65.964138] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [65.964224] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [65.964306] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [65.964414] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [65.964512] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [65.964606] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [65.964696] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [65.964770] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [65.964842] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [65.964914] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [65.964989] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [65.965069] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [65.965142] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [65.965214] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [65.965286] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [65.965359] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [65.965466] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [65.965563] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [65.965657] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [65.965750] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [65.965836] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [65.965914] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [65.966687] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [65.966931] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)
<7> [65.967044] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [65.967145] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [65.967237] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [65.967325] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [65.967407] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [65.967502] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [65.967596] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [65.967690] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [65.967763] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [65.967834] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [65.967903] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [65.967971] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [65.968039] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [65.968108] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [65.968177] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [65.968245] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [65.968334] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [65.968513] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [65.968597] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [65.968728] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [65.969523] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]
<7> [65.969665] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [65.971712] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [65.971807] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (468 ms remaining)
<7> [66.447289] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [66.515834] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [66.516198] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on
<7> [66.516506] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [66.552061] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [66.552184] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [66.552210] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4
<7> [66.552651] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [66.553061] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [66.553461] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [66.553899] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [66.721621] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [66.722075] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [66.722493] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [66.724568] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80
<7> [66.726080] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [66.726876] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [66.728035] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [66.729408] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [66.730510] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK
<7> [66.730846] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [66.732318] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [66.732691] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [66.733453] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [66.733979] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [66.734376] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [66.734806] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 13892
<7> [66.750793] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [66.752523] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [66.752987] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [66.773622] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [66.774103] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [66.774479] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [67.037162] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [67.037527] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [69.322475] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off
<7> [69.322904] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [77.116810] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [77.117309] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [77.117743] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [80.127338] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [80.127700] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [80.128163] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [80.128700] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [80.129121] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [80.129628] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0)
<7> [80.130074] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)
<7> [80.130650] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [80.131172] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)
<7> [80.131767] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)
<7> [80.132374] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)
<7> [80.132893] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)
<7> [80.133594] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)
<7> [80.134244] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)
<7> [80.134762] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)
<7> [80.135314] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)
<7> [80.135815] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)
<7> [80.136458] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)
<7> [80.136998] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)
<7> [80.137550] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)
<7> [80.138049] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)
<7> [80.138574] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)
<7> [80.139024] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)
<7> [80.139499] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)
<7> [80.139927] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)
<7> [80.140362] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)
<7> [80.140738] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)
<7> [80.141109] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)
<7> [80.141579] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)
<7> [80.141997] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)
<7> [80.142398] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)
<7> [80.142802] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)
<7> [80.143144] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [80.143500] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [80.143813] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [80.144101] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [80.144424] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)
<7> [80.144737] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)
<7> [80.145000] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [80.145283] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [80.145575] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0
<7> [80.145913] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [80.146103] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [80.146358] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0
<7> [80.146537] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0
<7> [80.146702] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [80.146862] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [80.147014] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [80.147181] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [80.147402] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0
<7> [80.147621] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400
<7> [80.147822] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400
<7> [80.148014] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [80.148197] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400
<7> [80.148421] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0
<7> [80.148603] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz
<7> [80.148801] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz
<7> [80.148994] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [80.149177] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [80.149343] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [80.149548] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]
<7> [80.149697] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [80.149840] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [80.149977] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [80.150112] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [80.150254] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [80.150387] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [80.150581] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [80.151352] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [80.151513] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2
<7> [80.152273] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [80.152395] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f
<7> [80.153027] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [80.153128] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [80.359717] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [80.360598] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [80.370113] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [80.370485] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [80.370742] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time
<7> [80.371152] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [80.371263] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060
<7> [80.422739] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [80.423140] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]
<7> [80.423214] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [80.423199] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [80.423600] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [80.424047] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [80.424712] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [80.425393] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [80.426128] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [80.426659] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [80.427117] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [80.427555] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [80.428115] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [80.428618] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [80.429060] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [80.429503] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [80.429940] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [80.430341] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [80.430778] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [80.431144] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [80.431500] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [80.431922] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [80.432395] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [80.432822] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [80.433164] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [80.433812] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [80.434307] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [80.434900] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [80.435273] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [80.435703] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [80.436016] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [80.437088] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [80.437423] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [80.437694] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [80.437751] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [80.437903] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [80.438248] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000
<7> [80.438540] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [80.438870] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [80.439143] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]
<7> [80.439454] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [80.439725] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [80.439998] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [80.440224] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [80.440444] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)
<7> [80.440715] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [80.440933] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [80.441125] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [80.441327] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [80.441513] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [80.441712] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [80.441882] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [80.442048] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [80.442206] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [80.442362] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [80.442516] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [80.442688] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [80.442842] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [80.442985] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [80.443122] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [80.443257] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [80.443389] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [80.443540] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [80.443704] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [80.443828] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [80.443959] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [80.444077] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [80.444193] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [80.444304] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [80.444414] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [80.444525] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [80.444646] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [80.444755] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [80.444864] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [80.444970] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [80.445075] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [80.445176] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [80.445275] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [80.445373] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [80.445510] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [80.445603] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1
<7> [80.445714] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [80.445820] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [80.445899] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [80.445965] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0
<7> [80.446030] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197
<7> [80.446097] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198
<7> [80.446177] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1
<7> [80.446296] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [80.446410] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [80.446511] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [80.446604] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [80.446700] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [80.446790] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz
<7> [80.446890] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz
<7> [80.446985] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [80.447083] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [80.447180] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [80.447280] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0
<7> [80.447360] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0
<7> [80.447445] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [80.447533] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [80.447702] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0
<7> [80.447807] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [80.447888] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [80.447968] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [80.448047] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [80.448126] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64
<7> [80.448205] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [80.448282] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [80.448358] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [80.448433] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [80.448508] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [80.448583] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [80.448679] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [80.448763] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [80.448850] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [80.448923] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [80.448998] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [80.449079] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [80.449158] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [80.449238] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [80.449315] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97
<7> [80.449388] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906
<7> [80.449465] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [80.449545] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [80.449638] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa
<7> [80.449722] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa
<7> [80.449801] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa
<7> [80.449874] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa
<7> [80.449947] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0
<7> [80.450018] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [80.450094] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [80.450173] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [80.450252] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [80.450324] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [80.450396] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [80.450468] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no
<7> [80.450542] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [80.450620] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [80.450700] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [80.450779] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [80.450856] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [80.450935] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [80.451015] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [80.451095] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [80.451169] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [80.451241] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [80.451313] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [80.451391] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [80.451469] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [80.451548] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [80.451639] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [80.451738] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [80.451830] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [80.451907] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [80.451985] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [80.452065] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [80.452142] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [80.452214] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [80.452286] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [80.452357] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [80.452428] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [80.452499] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [80.452569] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [80.452658] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [80.452735] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [80.453112] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A
<7> [80.453264] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)
<7> [80.453377] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [80.453479] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [80.453573] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [80.453710] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [80.453786] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [80.453872] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [80.453947] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [80.454019] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [80.454090] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [80.454158] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [80.454221] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [80.454283] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [80.454345] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [80.454407] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [80.454469] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [80.454530] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [80.454615] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [80.454783] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [80.454857] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [80.454969] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [80.455740] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]
<7> [80.455880] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [80.457893] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [80.457991] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (466 ms remaining)
<7> [80.458360] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [80.458458] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [80.458541] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [80.458639] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [80.928371] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060
<7> [81.009695] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [81.010063] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on
<7> [81.010433] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063
<7> [81.046403] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [81.046779] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [81.047109] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [81.047477] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [81.219671] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [81.220092] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [81.220424] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b
<7> [81.222630] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80
<7> [81.224216] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates
<7> [81.225261] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05
<7> [81.226757] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [81.228339] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1
<7> [81.229707] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK
<7> [81.230239] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4
<7> [81.231956] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful
<7> [81.232409] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4
<7> [81.233431] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A
<7> [81.234105] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [81.234579] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A
<7> [81.235135] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 13892
<7> [81.251043] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [81.252927] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [81.253353] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [81.273802] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [81.274319] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [81.274787] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [81.536032] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [81.536393] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [83.819404] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off
<7> [83.819806] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [91.533353] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [91.533859] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [91.534289] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<6> [91.728099] [IGT] kms_flip: finished subtest A-eDP1, FAIL
Created at 2026-04-16 00:11:04