igt@kms_flip@flip-vs-expired-vblank-interruptible@a-edp1 on shard-lnl@IGT

Detail	Value
Duration	10.95 seconds
Hostname	shard-lnl-4
Igt-Version	IGT-Version: 2.3-gd3c67e0f1 (x86_64) (Linux: 6.19.0-lgci-xe-xe-4575-c81e41f7aca96f583-debug+ x86_64)
Out	Using IGT_SRANDOM=1771520832 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: flip-vs-expired-vblank-interruptible Starting dynamic subtest: A-eDP1 2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1887 run_test() #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043() #4 ../tests/kms_flip.c:2043 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (10.951s)
Err	Starting subtest: flip-vs-expired-vblank-interruptible Starting dynamic subtest: A-eDP1 (kms_flip:9513) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:9513) CRITICAL: Failed assertion: end - start < 500 (kms_flip:9513) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 496.607086 last_received_ts = 496.606262 last_seq = 5666 current_ts = 496.623718 current_received_ts = 496.622925 current_seq = 5667 count = 459 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 56us (kms_flip:9513) DEBUG: name = flip last_ts = 496.623718 last_received_ts = 496.622925 last_seq = 5667 current_ts = 496.640381 current_received_ts = 496.639587 current_seq = 5668 count = 460 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 496.640381 last_received_ts = 496.639587 last_seq = 5668 current_ts = 496.657043 current_received_ts = 496.656250 current_seq = 5669 count = 461 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 496.657043 last_received_ts = 496.656250 last_seq = 5669 current_ts = 496.673706 current_received_ts = 496.672913 current_seq = 5670 count = 462 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 496.673706 last_received_ts = 496.672913 last_seq = 5670 current_ts = 496.690369 current_received_ts = 496.689575 current_seq = 5671 count = 463 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 46us (kms_flip:9513) DEBUG: name = flip last_ts = 496.690369 last_received_ts = 496.689575 last_seq = 5671 current_ts = 496.707031 current_received_ts = 496.706207 current_seq = 5672 count = 464 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 51us (kms_flip:9513) DEBUG: name = flip last_ts = 496.707031 last_received_ts = 496.706207 last_seq = 5672 current_ts = 496.723694 current_received_ts = 496.722931 current_seq = 5673 count = 465 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 151us (kms_flip:9513) DEBUG: name = flip last_ts = 496.723694 last_received_ts = 496.722931 last_seq = 5673 current_ts = 496.740326 current_received_ts = 496.739563 current_seq = 5674 count = 466 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 76us (kms_flip:9513) DEBUG: name = flip last_ts = 496.740326 last_received_ts = 496.739563 last_seq = 5674 current_ts = 496.756989 current_received_ts = 496.756195 current_seq = 5675 count = 467 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 69us (kms_flip:9513) DEBUG: name = flip last_ts = 496.756989 last_received_ts = 496.756195 last_seq = 5675 current_ts = 496.773651 current_received_ts = 496.772858 current_seq = 5676 count = 468 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 154us (kms_flip:9513) DEBUG: name = flip last_ts = 496.773651 last_received_ts = 496.772858 last_seq = 5676 current_ts = 496.790314 current_received_ts = 496.789520 current_seq = 5677 count = 469 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 76us (kms_flip:9513) DEBUG: name = flip last_ts = 496.790314 last_received_ts = 496.789520 last_seq = 5677 current_ts = 496.806976 current_received_ts = 496.806183 current_seq = 5678 count = 470 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 68us (kms_flip:9513) DEBUG: name = flip last_ts = 496.806976 last_received_ts = 496.806183 last_seq = 5678 current_ts = 496.823639 current_received_ts = 496.822845 current_seq = 5679 count = 471 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 58us (kms_flip:9513) DEBUG: name = flip last_ts = 496.823639 last_received_ts = 496.822845 last_seq = 5679 current_ts = 496.840302 current_received_ts = 496.839508 current_seq = 5680 count = 472 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 496.840302 last_received_ts = 496.839508 last_seq = 5680 current_ts = 496.856964 current_received_ts = 496.856140 current_seq = 5681 count = 473 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 42us (kms_flip:9513) DEBUG: name = flip last_ts = 496.856964 last_received_ts = 496.856140 last_seq = 5681 current_ts = 496.873596 current_received_ts = 496.872833 current_seq = 5682 count = 474 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 59us (kms_flip:9513) DEBUG: name = flip last_ts = 496.873596 last_received_ts = 496.872833 last_seq = 5682 current_ts = 496.890259 current_received_ts = 496.889465 current_seq = 5683 count = 475 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 496.890259 last_received_ts = 496.889465 last_seq = 5683 current_ts = 496.906921 current_received_ts = 496.906158 current_seq = 5684 count = 476 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 104us (kms_flip:9513) DEBUG: name = flip last_ts = 496.906921 last_received_ts = 496.906158 last_seq = 5684 current_ts = 496.923584 current_received_ts = 496.922791 current_seq = 5685 count = 477 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 63us (kms_flip:9513) DEBUG: name = flip last_ts = 496.923584 last_received_ts = 496.922791 last_seq = 5685 current_ts = 496.940247 current_received_ts = 496.939453 current_seq = 5686 count = 478 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 59us (kms_flip:9513) DEBUG: name = flip last_ts = 496.940247 last_received_ts = 496.939453 last_seq = 5686 current_ts = 496.956909 current_received_ts = 496.956116 current_seq = 5687 count = 479 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 86us (kms_flip:9513) DEBUG: name = flip last_ts = 496.956909 last_received_ts = 496.956116 last_seq = 5687 current_ts = 496.973572 current_received_ts = 496.972809 current_seq = 5688 count = 480 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 131us (kms_flip:9513) DEBUG: name = flip last_ts = 496.973572 last_received_ts = 496.972809 last_seq = 5688 current_ts = 496.990234 current_received_ts = 496.989441 current_seq = 5689 count = 481 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 84us (kms_flip:9513) DEBUG: name = flip last_ts = 496.990234 last_received_ts = 496.989441 last_seq = 5689 current_ts = 497.006866 current_received_ts = 497.006073 current_seq = 5690 count = 482 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 61us (kms_flip:9513) DEBUG: name = flip last_ts = 497.006866 last_received_ts = 497.006073 last_seq = 5690 current_ts = 497.023529 current_received_ts = 497.022766 current_seq = 5691 count = 483 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 59us (kms_flip:9513) DEBUG: name = flip last_ts = 497.023529 last_received_ts = 497.022766 last_seq = 5691 current_ts = 497.040192 current_received_ts = 497.039398 current_seq = 5692 count = 484 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 46us (kms_flip:9513) DEBUG: name = flip last_ts = 497.040192 last_received_ts = 497.039398 last_seq = 5692 current_ts = 497.056854 current_received_ts = 497.056061 current_seq = 5693 count = 485 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 57us (kms_flip:9513) DEBUG: name = flip last_ts = 497.056854 last_received_ts = 497.056061 last_seq = 5693 current_ts = 497.073517 current_received_ts = 497.072723 current_seq = 5694 count = 486 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 43us (kms_flip:9513) DEBUG: name = flip last_ts = 497.073517 last_received_ts = 497.072723 last_seq = 5694 current_ts = 497.090179 current_received_ts = 497.089355 current_seq = 5695 count = 487 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 62us (kms_flip:9513) DEBUG: name = flip last_ts = 497.090179 last_received_ts = 497.089355 last_seq = 5695 current_ts = 497.106842 current_received_ts = 497.106079 current_seq = 5696 count = 488 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 55us (kms_flip:9513) DEBUG: name = flip last_ts = 497.106842 last_received_ts = 497.106079 last_seq = 5696 current_ts = 497.123474 current_received_ts = 497.122711 current_seq = 5697 count = 489 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 497.123474 last_received_ts = 497.122711 last_seq = 5697 current_ts = 497.140137 current_received_ts = 497.139343 current_seq = 5698 count = 490 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 497.140137 last_received_ts = 497.139343 last_seq = 5698 current_ts = 497.156799 current_received_ts = 497.156036 current_seq = 5699 count = 491 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 497.156799 last_received_ts = 497.156036 last_seq = 5699 current_ts = 497.173462 current_received_ts = 497.172699 current_seq = 5700 count = 492 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 41us (kms_flip:9513) DEBUG: name = flip last_ts = 497.173462 last_received_ts = 497.172699 last_seq = 5700 current_ts = 497.190125 current_received_ts = 497.189331 current_seq = 5701 count = 493 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 497.190125 last_received_ts = 497.189331 last_seq = 5701 current_ts = 497.206787 current_received_ts = 497.206024 current_seq = 5702 count = 494 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 497.206787 last_received_ts = 497.206024 last_seq = 5702 current_ts = 497.223450 current_received_ts = 497.222656 current_seq = 5703 count = 495 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 497.223450 last_received_ts = 497.222656 last_seq = 5703 current_ts = 497.240112 current_received_ts = 497.239288 current_seq = 5704 count = 496 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 497.240112 last_received_ts = 497.239288 last_seq = 5704 current_ts = 497.256744 current_received_ts = 497.255981 current_seq = 5705 count = 497 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 61us (kms_flip:9513) DEBUG: name = flip last_ts = 497.256744 last_received_ts = 497.255981 last_seq = 5705 current_ts = 497.273407 current_received_ts = 497.272797 current_seq = 5706 count = 498 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 66us (kms_flip:9513) DEBUG: name = flip last_ts = 497.273407 last_received_ts = 497.272797 last_seq = 5706 current_ts = 497.290070 current_received_ts = 497.289276 current_seq = 5707 count = 499 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 68us (kms_flip:9513) DEBUG: name = flip last_ts = 497.290070 last_received_ts = 497.289276 last_seq = 5707 current_ts = 497.306732 current_received_ts = 497.305969 current_seq = 5708 count = 500 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 92us (kms_flip:9513) DEBUG: name = flip last_ts = 497.306732 last_received_ts = 497.305969 last_seq = 5708 current_ts = 497.323395 current_received_ts = 497.322601 current_seq = 5709 count = 501 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 58us (kms_flip:9513) DEBUG: name = flip last_ts = 497.323395 last_received_ts = 497.322601 last_seq = 5709 current_ts = 497.340057 current_received_ts = 497.339233 current_seq = 5710 count = 502 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 62us (kms_flip:9513) DEBUG: name = flip last_ts = 497.340057 last_received_ts = 497.339233 last_seq = 5710 current_ts = 497.356720 current_received_ts = 497.355927 current_seq = 5711 count = 503 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 55us (kms_flip:9513) DEBUG: name = flip last_ts = 497.356720 last_received_ts = 497.355927 last_seq = 5711 current_ts = 497.373352 current_received_ts = 497.372589 current_seq = 5712 count = 504 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 57us (kms_flip:9513) DEBUG: name = flip last_ts = 497.373352 last_received_ts = 497.372589 last_seq = 5712 current_ts = 497.390015 current_received_ts = 497.389221 current_seq = 5713 count = 505 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 56us (kms_flip:9513) DEBUG: name = flip last_ts = 497.390015 last_received_ts = 497.389221 last_seq = 5713 current_ts = 497.406677 current_received_ts = 497.405914 current_seq = 5714 count = 506 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 497.406677 last_received_ts = 497.405914 last_seq = 5714 current_ts = 497.423340 current_received_ts = 497.422577 current_seq = 5715 count = 507 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 50us (kms_flip:9513) DEBUG: name = flip last_ts = 497.423340 last_received_ts = 497.422577 last_seq = 5715 current_ts = 497.440002 current_received_ts = 497.439209 current_seq = 5716 count = 508 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 58us (kms_flip:9513) DEBUG: name = flip last_ts = 497.440002 last_received_ts = 497.439209 last_seq = 5716 current_ts = 497.456665 current_received_ts = 497.455872 current_seq = 5717 count = 509 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 497.456665 last_received_ts = 497.455872 last_seq = 5717 current_ts = 497.473328 current_received_ts = 497.472534 current_seq = 5718 count = 510 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 49us (kms_flip:9513) DEBUG: name = flip last_ts = 497.473328 last_received_ts = 497.472534 last_seq = 5718 current_ts = 497.489990 current_received_ts = 497.489166 current_seq = 5719 count = 511 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 497.489990 last_received_ts = 497.489166 last_seq = 5719 current_ts = 497.506622 current_received_ts = 497.505859 current_seq = 5720 count = 512 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 57us (kms_flip:9513) DEBUG: name = flip last_ts = 497.506622 last_received_ts = 497.505859 last_seq = 5720 current_ts = 497.523285 current_received_ts = 497.522522 current_seq = 5721 count = 513 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 497.523285 last_received_ts = 497.522522 last_seq = 5721 current_ts = 497.539948 current_received_ts = 497.539154 current_seq = 5722 count = 514 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 497.539948 last_received_ts = 497.539154 last_seq = 5722 current_ts = 497.556610 current_received_ts = 497.555786 current_seq = 5723 count = 515 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 497.556610 last_received_ts = 497.555786 last_seq = 5723 current_ts = 497.573273 current_received_ts = 497.572479 current_seq = 5724 count = 516 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 58us (kms_flip:9513) DEBUG: name = flip last_ts = 497.573273 last_received_ts = 497.572479 last_seq = 5724 current_ts = 497.589935 current_received_ts = 497.589172 current_seq = 5725 count = 517 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 46us (kms_flip:9513) DEBUG: name = flip last_ts = 497.589935 last_received_ts = 497.589172 last_seq = 5725 current_ts = 497.606598 current_received_ts = 497.605804 current_seq = 5726 count = 518 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 77us (kms_flip:9513) DEBUG: name = flip last_ts = 497.606598 last_received_ts = 497.605804 last_seq = 5726 current_ts = 497.623260 current_received_ts = 497.622467 current_seq = 5727 count = 519 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 60us (kms_flip:9513) DEBUG: name = flip last_ts = 497.623260 last_received_ts = 497.622467 last_seq = 5727 current_ts = 497.639893 current_received_ts = 497.639099 current_seq = 5728 count = 520 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 497.639893 last_received_ts = 497.639099 last_seq = 5728 current_ts = 497.656555 current_received_ts = 497.655762 current_seq = 5729 count = 521 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 497.656555 last_received_ts = 497.655762 last_seq = 5729 current_ts = 497.673218 current_received_ts = 497.672455 current_seq = 5730 count = 522 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 44us (kms_flip:9513) DEBUG: name = flip last_ts = 497.673218 last_received_ts = 497.672455 last_seq = 5730 current_ts = 497.689880 current_received_ts = 497.689087 current_seq = 5731 count = 523 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 48us (kms_flip:9513) DEBUG: name = flip last_ts = 497.689880 last_received_ts = 497.689087 last_seq = 5731 current_ts = 497.706543 current_received_ts = 497.705780 current_seq = 5732 count = 524 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 497.706543 last_received_ts = 497.705780 last_seq = 5732 current_ts = 497.723206 current_received_ts = 497.722412 current_seq = 5733 count = 525 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 65us (kms_flip:9513) DEBUG: name = flip last_ts = 497.723206 last_received_ts = 497.722412 last_seq = 5733 current_ts = 497.739868 current_received_ts = 497.739075 current_seq = 5734 count = 526 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 56us (kms_flip:9513) DEBUG: name = flip last_ts = 497.739868 last_received_ts = 497.739075 last_seq = 5734 current_ts = 497.756500 current_received_ts = 497.755737 current_seq = 5735 count = 527 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 497.756500 last_received_ts = 497.755737 last_seq = 5735 current_ts = 497.773163 current_received_ts = 497.772369 current_seq = 5736 count = 528 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 497.773163 last_received_ts = 497.772369 last_seq = 5736 current_ts = 497.789825 current_received_ts = 497.789062 current_seq = 5737 count = 529 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 497.789825 last_received_ts = 497.789062 last_seq = 5737 current_ts = 497.806488 current_received_ts = 497.805725 current_seq = 5738 count = 530 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 80us (kms_flip:9513) DEBUG: name = flip last_ts = 497.806488 last_received_ts = 497.805725 last_seq = 5738 current_ts = 497.823151 current_received_ts = 497.822357 current_seq = 5739 count = 531 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 97us (kms_flip:9513) DEBUG: name = flip last_ts = 497.823151 last_received_ts = 497.822357 last_seq = 5739 current_ts = 497.839813 current_received_ts = 497.839020 current_seq = 5740 count = 532 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 69us (kms_flip:9513) DEBUG: name = flip last_ts = 497.839813 last_received_ts = 497.839020 last_seq = 5740 current_ts = 497.856476 current_received_ts = 497.855682 current_seq = 5741 count = 533 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 98us (kms_flip:9513) DEBUG: name = flip last_ts = 497.856476 last_received_ts = 497.855682 last_seq = 5741 current_ts = 497.873138 current_received_ts = 497.872314 current_seq = 5742 count = 534 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 43us (kms_flip:9513) DEBUG: name = flip last_ts = 497.873138 last_received_ts = 497.872314 last_seq = 5742 current_ts = 497.889771 current_received_ts = 497.889008 current_seq = 5743 count = 535 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 57us (kms_flip:9513) DEBUG: name = flip last_ts = 497.889771 last_received_ts = 497.889008 last_seq = 5743 current_ts = 497.906433 current_received_ts = 497.905670 current_seq = 5744 count = 536 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 51us (kms_flip:9513) DEBUG: name = flip last_ts = 497.906433 last_received_ts = 497.905670 last_seq = 5744 current_ts = 497.923096 current_received_ts = 497.922302 current_seq = 5745 count = 537 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 51us (kms_flip:9513) DEBUG: name = flip last_ts = 497.923096 last_received_ts = 497.922302 last_seq = 5745 current_ts = 497.939758 current_received_ts = 497.938965 current_seq = 5746 count = 538 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 81us (kms_flip:9513) DEBUG: name = flip last_ts = 497.939758 last_received_ts = 497.938965 last_seq = 5746 current_ts = 497.956421 current_received_ts = 497.955627 current_seq = 5747 count = 539 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 55us (kms_flip:9513) DEBUG: name = flip last_ts = 497.956421 last_received_ts = 497.955627 last_seq = 5747 current_ts = 497.973083 current_received_ts = 497.972260 current_seq = 5748 count = 540 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 62us (kms_flip:9513) DEBUG: name = flip last_ts = 497.973083 last_received_ts = 497.972260 last_seq = 5748 current_ts = 497.989746 current_received_ts = 497.988922 current_seq = 5749 count = 541 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 55us (kms_flip:9513) DEBUG: name = flip last_ts = 497.989746 last_received_ts = 497.988922 last_seq = 5749 current_ts = 498.006409 current_received_ts = 498.005646 current_seq = 5750 count = 542 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 93us (kms_flip:9513) DEBUG: name = flip last_ts = 498.006409 last_received_ts = 498.005646 last_seq = 5750 current_ts = 498.023041 current_received_ts = 498.022247 current_seq = 5751 count = 543 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 41us (kms_flip:9513) DEBUG: name = flip last_ts = 498.023041 last_received_ts = 498.022247 last_seq = 5751 current_ts = 498.039703 current_received_ts = 498.038940 current_seq = 5752 count = 544 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 57us (kms_flip:9513) DEBUG: name = flip last_ts = 498.039703 last_received_ts = 498.038940 last_seq = 5752 current_ts = 498.056366 current_received_ts = 498.055603 current_seq = 5753 count = 545 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 40us (kms_flip:9513) DEBUG: name = flip last_ts = 498.056366 last_received_ts = 498.055603 last_seq = 5753 current_ts = 498.073029 current_received_ts = 498.072235 current_seq = 5754 count = 546 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 58us (kms_flip:9513) DEBUG: name = flip last_ts = 498.073029 last_received_ts = 498.072235 last_seq = 5754 current_ts = 498.089691 current_received_ts = 498.088898 current_seq = 5755 count = 547 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 498.089691 last_received_ts = 498.088898 last_seq = 5755 current_ts = 498.106354 current_received_ts = 498.105743 current_seq = 5756 count = 548 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 76us (kms_flip:9513) DEBUG: name = flip last_ts = 498.106354 last_received_ts = 498.105743 last_seq = 5756 current_ts = 498.123016 current_received_ts = 498.122223 current_seq = 5757 count = 549 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 65us (kms_flip:9513) DEBUG: name = flip last_ts = 498.123016 last_received_ts = 498.122223 last_seq = 5757 current_ts = 498.139679 current_received_ts = 498.138855 current_seq = 5758 count = 550 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 66us (kms_flip:9513) DEBUG: name = flip last_ts = 498.139679 last_received_ts = 498.138855 last_seq = 5758 current_ts = 498.156311 current_received_ts = 498.155548 current_seq = 5759 count = 551 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 86us (kms_flip:9513) DEBUG: name = flip last_ts = 498.156311 last_received_ts = 498.155548 last_seq = 5759 current_ts = 498.172974 current_received_ts = 498.172180 current_seq = 5760 count = 552 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 55us (kms_flip:9513) DEBUG: name = flip last_ts = 498.172974 last_received_ts = 498.172180 last_seq = 5760 current_ts = 498.189636 current_received_ts = 498.188843 current_seq = 5761 count = 553 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 498.189636 last_received_ts = 498.188843 last_seq = 5761 current_ts = 498.206299 current_received_ts = 498.205505 current_seq = 5762 count = 554 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 498.206299 last_received_ts = 498.205505 last_seq = 5762 current_ts = 498.222961 current_received_ts = 498.222168 current_seq = 5763 count = 555 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 44us (kms_flip:9513) DEBUG: name = flip last_ts = 498.222961 last_received_ts = 498.222168 last_seq = 5763 current_ts = 498.239624 current_received_ts = 498.238831 current_seq = 5764 count = 556 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 498.239624 last_received_ts = 498.238831 last_seq = 5764 current_ts = 498.256256 current_received_ts = 498.255493 current_seq = 5765 count = 557 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 41us (kms_flip:9513) DEBUG: name = flip last_ts = 498.256256 last_received_ts = 498.255493 last_seq = 5765 current_ts = 498.272949 current_received_ts = 498.272125 current_seq = 5766 count = 558 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 498.272949 last_received_ts = 498.272125 last_seq = 5766 current_ts = 498.289581 current_received_ts = 498.288818 current_seq = 5767 count = 559 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 51us (kms_flip:9513) DEBUG: name = flip last_ts = 498.289581 last_received_ts = 498.288818 last_seq = 5767 current_ts = 498.306244 current_received_ts = 498.305481 current_seq = 5768 count = 560 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 59us (kms_flip:9513) DEBUG: name = flip last_ts = 498.306244 last_received_ts = 498.305481 last_seq = 5768 current_ts = 498.322906 current_received_ts = 498.322113 current_seq = 5769 count = 561 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 42us (kms_flip:9513) DEBUG: name = flip last_ts = 498.322906 last_received_ts = 498.322113 last_seq = 5769 current_ts = 498.339569 current_received_ts = 498.338776 current_seq = 5770 count = 562 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 58us (kms_flip:9513) DEBUG: name = flip last_ts = 498.339569 last_received_ts = 498.338776 last_seq = 5770 current_ts = 498.356232 current_received_ts = 498.355438 current_seq = 5771 count = 563 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 57us (kms_flip:9513) DEBUG: name = flip last_ts = 498.356232 last_received_ts = 498.355438 last_seq = 5771 current_ts = 498.372894 current_received_ts = 498.372101 current_seq = 5772 count = 564 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 58us (kms_flip:9513) DEBUG: name = flip last_ts = 498.372894 last_received_ts = 498.372101 last_seq = 5772 current_ts = 498.389526 current_received_ts = 498.388763 current_seq = 5773 count = 565 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 52us (kms_flip:9513) DEBUG: name = flip last_ts = 498.389526 last_received_ts = 498.388763 last_seq = 5773 current_ts = 498.406189 current_received_ts = 498.405396 current_seq = 5774 count = 566 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 498.406189 last_received_ts = 498.405396 last_seq = 5774 current_ts = 498.422852 current_received_ts = 498.422089 current_seq = 5775 count = 567 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 89us (kms_flip:9513) DEBUG: name = flip last_ts = 498.422852 last_received_ts = 498.422089 last_seq = 5775 current_ts = 498.439514 current_received_ts = 498.438751 current_seq = 5776 count = 568 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 68us (kms_flip:9513) DEBUG: name = flip last_ts = 498.439514 last_received_ts = 498.438751 last_seq = 5776 current_ts = 498.456177 current_received_ts = 498.455383 current_seq = 5777 count = 569 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 77us (kms_flip:9513) DEBUG: name = flip last_ts = 498.456177 last_received_ts = 498.455383 last_seq = 5777 current_ts = 498.472839 current_received_ts = 498.472076 current_seq = 5778 count = 570 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 59us (kms_flip:9513) DEBUG: name = flip last_ts = 498.472839 last_received_ts = 498.472076 last_seq = 5778 current_ts = 498.489502 current_received_ts = 498.488708 current_seq = 5779 count = 571 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 54us (kms_flip:9513) DEBUG: name = flip last_ts = 498.489502 last_received_ts = 498.488708 last_seq = 5779 current_ts = 498.506165 current_received_ts = 498.505371 current_seq = 5780 count = 572 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 61us (kms_flip:9513) DEBUG: name = flip last_ts = 498.506165 last_received_ts = 498.505371 last_seq = 5780 current_ts = 498.522797 current_received_ts = 498.522034 current_seq = 5781 count = 573 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 58us (kms_flip:9513) DEBUG: name = flip last_ts = 498.522797 last_received_ts = 498.522034 last_seq = 5781 current_ts = 498.539459 current_received_ts = 498.538666 current_seq = 5782 count = 574 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 56us (kms_flip:9513) DEBUG: name = flip last_ts = 498.539459 last_received_ts = 498.538666 last_seq = 5782 current_ts = 498.556122 current_received_ts = 498.555359 current_seq = 5783 count = 575 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 122us (kms_flip:9513) DEBUG: name = flip last_ts = 498.556122 last_received_ts = 498.555359 last_seq = 5783 current_ts = 498.572784 current_received_ts = 498.572021 current_seq = 5784 count = 576 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 498.572784 last_received_ts = 498.572021 last_seq = 5784 current_ts = 498.589447 current_received_ts = 498.588654 current_seq = 5785 count = 577 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 56us (kms_flip:9513) DEBUG: name = flip last_ts = 498.589447 last_received_ts = 498.588654 last_seq = 5785 current_ts = 498.606110 current_received_ts = 498.605286 current_seq = 5786 count = 578 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 53us (kms_flip:9513) DEBUG: name = flip last_ts = 498.606110 last_received_ts = 498.605286 last_seq = 5786 current_ts = 498.622772 current_received_ts = 498.621979 current_seq = 5787 count = 579 seq_step = 1 (kms_flip:9513) DEBUG: Vblank took 743us (kms_flip:9513) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:9513) CRITICAL: Failed assertion: end - start < 500 (kms_flip:9513) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:9513) igt_core-INFO: Stack trace: (kms_flip:9513) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:9513) igt_core-INFO: #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() (kms_flip:9513) igt_core-INFO: #2 ../tests/kms_flip.c:1887 run_test() (kms_flip:9513) igt_core-INFO: #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043() (kms_flip:9513) igt_core-INFO: #4 ../tests/kms_flip.c:2043 main() (kms_flip:9513) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:9513) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:9513) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (10.951s)
Dmesg	<6> [595.162310] Console: switching to colour dummy device 80x25 <6> [595.162602] [IGT] kms_flip: executing <7> [595.168092] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] <7> [595.168101] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1] <7> [595.168546] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [595.168636] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected <7> [595.168865] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] <7> [595.168867] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2] <7> [595.168979] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [595.169062] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected <7> [595.169299] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] <7> [595.169301] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3] <7> [595.169435] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [595.169531] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected <7> [595.169795] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] <7> [595.169797] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:392:eDP-1] <7> [595.169895] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on <7> [595.169997] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f <7> [595.170416] 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> [595.170727] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [595.170831] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [595.170934] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [595.171053] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz <5> [595.171057] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [595.171058] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [595.171059] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] DisplayID extension version 0x13, primary use 0x00 <7> [595.171061] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <5> [595.171063] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [595.171064] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD monitor <5> [595.171066] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [595.171067] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD size 20, SAD count 0 <5> [595.171069] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [595.171081] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] VRR capable: yes <7> [595.171159] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [595.171258] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <5> [595.171791] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [595.171793] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [595.171794] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [595.171849] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] probed modes: <7> [595.171851] 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> [595.171854] 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> [595.171866] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] <7> [595.171869] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1] <7> [595.172016] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected <7> [595.172027] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] <7> [595.172029] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2] <7> [595.172144] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected <7> [595.172150] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] <7> [595.172152] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3] <7> [595.172382] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected <6> [595.175788] [IGT] kms_flip: starting subtest flip-vs-expired-vblank-interruptible <6> [595.177105] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [595.187057] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:428] <7> [595.187502] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:437] <7> [595.238118] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [595.238209] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [595.238389] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [595.238511] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [595.238607] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [595.238700] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150: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> [595.238790] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [595.238879] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [595.238971] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [595.239062] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [595.239151] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [595.239247] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [595.239354] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [595.239465] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [595.239561] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [595.239642] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [595.239721] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [595.239799] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [595.239875] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [595.239951] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [595.240026] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [595.240100] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [595.240180] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [595.240271] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [595.240370] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [595.240462] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [595.240541] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [595.240613] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [595.240684] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [595.240762] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [595.240839] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [595.240917] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [595.240995] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [595.241066] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [595.241136] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [595.241208] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [595.241335] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [595.241440] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [595.241539] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 432000, found 0) <7> [595.241620] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset <7> [595.241697] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:150:pipe A] releasing DPLL 0 <7> [595.241799] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [595.241865] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [595.241938] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [595.241993] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [595.242049] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] level wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm <7> [595.242103] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.242157] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.242210] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.242313] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 0 num active planes 0 <7> [595.242437] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [595.242545] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [595.242626] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [595.242708] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [595.242795] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [595.242880] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [595.242993] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [595.243074] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [595.243149] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [595.243233] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [595.243363] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: no [modeset] <7> [595.243471] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [NOFB], visible: no <7> [595.243562] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no <7> [595.243638] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no <7> [595.243712] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no <7> [595.243786] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no <7> [595.243858] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no <7> [595.243986] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [595.244077] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [595.244206] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [595.263968] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [595.264533] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [595.466460] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 0 <7> [595.467006] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [595.477790] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power off <7> [595.478147] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power off time <7> [595.478247] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [595.478545] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [595.478681] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short <7> [595.529577] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [595.529995] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:150:pipe A] <7> [595.530047] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [595.530528] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [595.530850] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short <7> [595.531198] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [595.531560] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [595.532043] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [595.532577] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A] <7> [595.532948] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1] <7> [595.533261] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A] <7> [595.533671] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B] <7> [595.533970] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C] <7> [595.534268] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2] <7> [595.534601] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A] <7> [595.534880] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B] <7> [595.535155] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C] <7> [595.535458] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3] <7> [595.535755] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A] <7> [595.536049] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B] <7> [595.536361] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C] <7> [595.536627] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1] <7> [595.537009] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [595.537278] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [595.537610] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [595.538146] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [595.538603] 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> [595.539060] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A] <7> [595.539400] 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> [595.539861] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [595.540148] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [595.541037] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B] <7> [595.541432] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:388:pipe C] <7> [595.541767] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [595.541839] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:392:eDP-1] <7> [595.542022] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:392:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [595.542473] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:391:DDI A/PHY A][CRTC:150: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> [595.542807] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000 <7> [595.543135] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [595.543480] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:391:DDI A/PHY A] [CRTC:150:pipe A] <7> [595.543801] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [595.544138] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [595.544445] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [595.544744] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [595.545005] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288) <7> [595.545260] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [595.545577] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [595.545813] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [595.546029] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [595.546274] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880) <7> [595.546518] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040) <7> [595.546730] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928) <7> [595.546915] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960) <7> [595.547099] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [595.547274] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800) <7> [595.547502] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803) <7> [595.547667] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809) <7> [595.547829] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [595.547983] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906) <7> [595.548136] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [595.548285] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [595.548455] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880) <7> [595.548601] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040) <7> [595.548743] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928) <7> [595.548877] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960) <7> [595.549009] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [595.549140] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800) <7> [595.549266] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803) <7> [595.549413] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809) <7> [595.549543] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [595.549670] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906) <7> [595.549795] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [595.549921] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [595.550039] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [595.550156] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [595.550266] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [595.550392] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [595.550501] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 432000) <7> [595.550610] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset <7> [595.550770] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [595.550863] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [595.551001] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [595.551077] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [595.551153] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm <7> [595.551228] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.551300] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.551394] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.551484] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 1390840 num active planes 1 <7> [595.551611] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [595.551719] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [595.551819] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [595.551915] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [595.552009] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [595.552101] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 173855 kHz <7> [595.552210] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [595.552303] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [595.552419] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [595.552522] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [595.552634] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated DPLL 0 <7> [595.552727] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving DPLL 0 <7> [595.552810] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset] <7> [595.552894] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [595.552979] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0 <7> [595.553060] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [595.553135] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [595.553209] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [595.553282] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [595.553408] 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> [595.553507] 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> [595.553604] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [595.553681] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [595.553755] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [595.553828] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0 <7> [595.553902] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [595.553976] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [595.554049] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [595.554124] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [595.554197] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [595.554269] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [595.554359] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [595.554455] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [595.554550] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [595.554645] 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> [595.554725] 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> [595.554801] 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> [595.554875] 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> [595.554950] 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> [595.555024] 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> [595.555097] 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> [595.555170] 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> [595.555242] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855 <7> [595.555325] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [595.555432] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [595.555538] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [595.555629] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [595.555701] 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> [595.555772] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no, <7> [595.555842] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1. <7> [595.555914] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [595.555990] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [595.556066] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1 <7> [595.556141] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [595.556216] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [595.556284] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [595.556372] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23 <7> [595.556475] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [595.556579] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [595.556672] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [595.556752] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [595.556822] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [595.556893] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [595.556975] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [595.557061] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [595.557147] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [595.557228] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [595.557297] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [595.557394] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [595.557488] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [595.557581] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [FB:428] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [595.557663] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [595.557735] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [595.557807] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no <7> [595.557878] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no <7> [595.557948] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no <7> [595.558018] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no <7> [595.558088] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no <7> [595.558446] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [595.558609] 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> [595.558712] 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> [595.558806] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [595.558891] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [595.558970] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A] <7> [595.559034] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1] <7> [595.559098] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A] <7> [595.559162] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B] <7> [595.559225] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C] <7> [595.559286] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2] <7> [595.559366] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A] <7> [595.559444] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B] <7> [595.559520] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C] <7> [595.559596] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3] <7> [595.559661] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A] <7> [595.559723] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B] <7> [595.559784] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C] <7> [595.559866] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [595.560021] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [595.560079] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [595.560181] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [595.561432] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:150:pipe A] <7> [595.561562] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [595.563531] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power on <7> [595.563629] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining) <7> [595.566879] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [595.566998] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long <7> [595.567084] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [595.567179] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [596.034671] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [596.136411] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [596.136843] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power on <7> [596.137176] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [596.173181] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [596.173809] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long <7> [596.174292] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [596.174777] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [596.210694] 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> [596.210707] 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> [596.210836] 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> [596.349998] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [596.350428] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on <7> [596.350899] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [596.353160] 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> [596.354735] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [596.355589] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05 <7> [596.356809] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [596.358236] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [596.359383] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Clock recovery OK <7> [596.359787] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [596.361313] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [596.361675] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4 <7> [596.362467] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [596.363036] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [596.363463] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [596.363919] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 4518 <7> [596.379783] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [596.381438] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1] <7> [596.381842] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A] <7> [598.900412] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD off <7> [598.900946] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067 <7> [606.078707] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [606.079063] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [606.079318] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [606.129215] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

10.95 seconds

Hostname

shard-lnl-4

Igt-Version

IGT-Version: 2.3-gd3c67e0f1 (x86_64) (Linux: 6.19.0-lgci-xe-xe-4575-c81e41f7aca96f583-debug+ x86_64)

Out

Using IGT_SRANDOM=1771520832 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: flip-vs-expired-vblank-interruptible
Starting dynamic subtest: A-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (10.951s)

Err

Starting subtest: flip-vs-expired-vblank-interruptible
Starting dynamic subtest: A-eDP1
(kms_flip:9513) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:9513) CRITICAL: Failed assertion: end - start < 500
(kms_flip:9513) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.607086
last_received_ts = 496.606262
last_seq = 5666
current_ts = 496.623718
current_received_ts = 496.622925
current_seq = 5667
count = 459
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 56us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.623718
last_received_ts = 496.622925
last_seq = 5667
current_ts = 496.640381
current_received_ts = 496.639587
current_seq = 5668
count = 460
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.640381
last_received_ts = 496.639587
last_seq = 5668
current_ts = 496.657043
current_received_ts = 496.656250
current_seq = 5669
count = 461
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.657043
last_received_ts = 496.656250
last_seq = 5669
current_ts = 496.673706
current_received_ts = 496.672913
current_seq = 5670
count = 462
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.673706
last_received_ts = 496.672913
last_seq = 5670
current_ts = 496.690369
current_received_ts = 496.689575
current_seq = 5671
count = 463
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 46us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.690369
last_received_ts = 496.689575
last_seq = 5671
current_ts = 496.707031
current_received_ts = 496.706207
current_seq = 5672
count = 464
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 51us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.707031
last_received_ts = 496.706207
last_seq = 5672
current_ts = 496.723694
current_received_ts = 496.722931
current_seq = 5673
count = 465
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 151us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.723694
last_received_ts = 496.722931
last_seq = 5673
current_ts = 496.740326
current_received_ts = 496.739563
current_seq = 5674
count = 466
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 76us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.740326
last_received_ts = 496.739563
last_seq = 5674
current_ts = 496.756989
current_received_ts = 496.756195
current_seq = 5675
count = 467
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 69us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.756989
last_received_ts = 496.756195
last_seq = 5675
current_ts = 496.773651
current_received_ts = 496.772858
current_seq = 5676
count = 468
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 154us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.773651
last_received_ts = 496.772858
last_seq = 5676
current_ts = 496.790314
current_received_ts = 496.789520
current_seq = 5677
count = 469
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 76us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.790314
last_received_ts = 496.789520
last_seq = 5677
current_ts = 496.806976
current_received_ts = 496.806183
current_seq = 5678
count = 470
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 68us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.806976
last_received_ts = 496.806183
last_seq = 5678
current_ts = 496.823639
current_received_ts = 496.822845
current_seq = 5679
count = 471
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 58us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.823639
last_received_ts = 496.822845
last_seq = 5679
current_ts = 496.840302
current_received_ts = 496.839508
current_seq = 5680
count = 472
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.840302
last_received_ts = 496.839508
last_seq = 5680
current_ts = 496.856964
current_received_ts = 496.856140
current_seq = 5681
count = 473
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 42us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.856964
last_received_ts = 496.856140
last_seq = 5681
current_ts = 496.873596
current_received_ts = 496.872833
current_seq = 5682
count = 474
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 59us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.873596
last_received_ts = 496.872833
last_seq = 5682
current_ts = 496.890259
current_received_ts = 496.889465
current_seq = 5683
count = 475
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.890259
last_received_ts = 496.889465
last_seq = 5683
current_ts = 496.906921
current_received_ts = 496.906158
current_seq = 5684
count = 476
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 104us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.906921
last_received_ts = 496.906158
last_seq = 5684
current_ts = 496.923584
current_received_ts = 496.922791
current_seq = 5685
count = 477
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 63us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.923584
last_received_ts = 496.922791
last_seq = 5685
current_ts = 496.940247
current_received_ts = 496.939453
current_seq = 5686
count = 478
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 59us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.940247
last_received_ts = 496.939453
last_seq = 5686
current_ts = 496.956909
current_received_ts = 496.956116
current_seq = 5687
count = 479
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 86us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.956909
last_received_ts = 496.956116
last_seq = 5687
current_ts = 496.973572
current_received_ts = 496.972809
current_seq = 5688
count = 480
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 131us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.973572
last_received_ts = 496.972809
last_seq = 5688
current_ts = 496.990234
current_received_ts = 496.989441
current_seq = 5689
count = 481
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 84us
(kms_flip:9513) DEBUG: name = flip
last_ts = 496.990234
last_received_ts = 496.989441
last_seq = 5689
current_ts = 497.006866
current_received_ts = 497.006073
current_seq = 5690
count = 482
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 61us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.006866
last_received_ts = 497.006073
last_seq = 5690
current_ts = 497.023529
current_received_ts = 497.022766
current_seq = 5691
count = 483
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 59us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.023529
last_received_ts = 497.022766
last_seq = 5691
current_ts = 497.040192
current_received_ts = 497.039398
current_seq = 5692
count = 484
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 46us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.040192
last_received_ts = 497.039398
last_seq = 5692
current_ts = 497.056854
current_received_ts = 497.056061
current_seq = 5693
count = 485
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 57us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.056854
last_received_ts = 497.056061
last_seq = 5693
current_ts = 497.073517
current_received_ts = 497.072723
current_seq = 5694
count = 486
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 43us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.073517
last_received_ts = 497.072723
last_seq = 5694
current_ts = 497.090179
current_received_ts = 497.089355
current_seq = 5695
count = 487
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 62us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.090179
last_received_ts = 497.089355
last_seq = 5695
current_ts = 497.106842
current_received_ts = 497.106079
current_seq = 5696
count = 488
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 55us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.106842
last_received_ts = 497.106079
last_seq = 5696
current_ts = 497.123474
current_received_ts = 497.122711
current_seq = 5697
count = 489
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.123474
last_received_ts = 497.122711
last_seq = 5697
current_ts = 497.140137
current_received_ts = 497.139343
current_seq = 5698
count = 490
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.140137
last_received_ts = 497.139343
last_seq = 5698
current_ts = 497.156799
current_received_ts = 497.156036
current_seq = 5699
count = 491
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.156799
last_received_ts = 497.156036
last_seq = 5699
current_ts = 497.173462
current_received_ts = 497.172699
current_seq = 5700
count = 492
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 41us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.173462
last_received_ts = 497.172699
last_seq = 5700
current_ts = 497.190125
current_received_ts = 497.189331
current_seq = 5701
count = 493
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.190125
last_received_ts = 497.189331
last_seq = 5701
current_ts = 497.206787
current_received_ts = 497.206024
current_seq = 5702
count = 494
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.206787
last_received_ts = 497.206024
last_seq = 5702
current_ts = 497.223450
current_received_ts = 497.222656
current_seq = 5703
count = 495
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.223450
last_received_ts = 497.222656
last_seq = 5703
current_ts = 497.240112
current_received_ts = 497.239288
current_seq = 5704
count = 496
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.240112
last_received_ts = 497.239288
last_seq = 5704
current_ts = 497.256744
current_received_ts = 497.255981
current_seq = 5705
count = 497
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 61us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.256744
last_received_ts = 497.255981
last_seq = 5705
current_ts = 497.273407
current_received_ts = 497.272797
current_seq = 5706
count = 498
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 66us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.273407
last_received_ts = 497.272797
last_seq = 5706
current_ts = 497.290070
current_received_ts = 497.289276
current_seq = 5707
count = 499
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 68us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.290070
last_received_ts = 497.289276
last_seq = 5707
current_ts = 497.306732
current_received_ts = 497.305969
current_seq = 5708
count = 500
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 92us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.306732
last_received_ts = 497.305969
last_seq = 5708
current_ts = 497.323395
current_received_ts = 497.322601
current_seq = 5709
count = 501
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 58us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.323395
last_received_ts = 497.322601
last_seq = 5709
current_ts = 497.340057
current_received_ts = 497.339233
current_seq = 5710
count = 502
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 62us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.340057
last_received_ts = 497.339233
last_seq = 5710
current_ts = 497.356720
current_received_ts = 497.355927
current_seq = 5711
count = 503
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 55us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.356720
last_received_ts = 497.355927
last_seq = 5711
current_ts = 497.373352
current_received_ts = 497.372589
current_seq = 5712
count = 504
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 57us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.373352
last_received_ts = 497.372589
last_seq = 5712
current_ts = 497.390015
current_received_ts = 497.389221
current_seq = 5713
count = 505
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 56us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.390015
last_received_ts = 497.389221
last_seq = 5713
current_ts = 497.406677
current_received_ts = 497.405914
current_seq = 5714
count = 506
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.406677
last_received_ts = 497.405914
last_seq = 5714
current_ts = 497.423340
current_received_ts = 497.422577
current_seq = 5715
count = 507
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 50us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.423340
last_received_ts = 497.422577
last_seq = 5715
current_ts = 497.440002
current_received_ts = 497.439209
current_seq = 5716
count = 508
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 58us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.440002
last_received_ts = 497.439209
last_seq = 5716
current_ts = 497.456665
current_received_ts = 497.455872
current_seq = 5717
count = 509
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.456665
last_received_ts = 497.455872
last_seq = 5717
current_ts = 497.473328
current_received_ts = 497.472534
current_seq = 5718
count = 510
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 49us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.473328
last_received_ts = 497.472534
last_seq = 5718
current_ts = 497.489990
current_received_ts = 497.489166
current_seq = 5719
count = 511
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.489990
last_received_ts = 497.489166
last_seq = 5719
current_ts = 497.506622
current_received_ts = 497.505859
current_seq = 5720
count = 512
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 57us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.506622
last_received_ts = 497.505859
last_seq = 5720
current_ts = 497.523285
current_received_ts = 497.522522
current_seq = 5721
count = 513
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.523285
last_received_ts = 497.522522
last_seq = 5721
current_ts = 497.539948
current_received_ts = 497.539154
current_seq = 5722
count = 514
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.539948
last_received_ts = 497.539154
last_seq = 5722
current_ts = 497.556610
current_received_ts = 497.555786
current_seq = 5723
count = 515
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.556610
last_received_ts = 497.555786
last_seq = 5723
current_ts = 497.573273
current_received_ts = 497.572479
current_seq = 5724
count = 516
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 58us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.573273
last_received_ts = 497.572479
last_seq = 5724
current_ts = 497.589935
current_received_ts = 497.589172
current_seq = 5725
count = 517
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 46us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.589935
last_received_ts = 497.589172
last_seq = 5725
current_ts = 497.606598
current_received_ts = 497.605804
current_seq = 5726
count = 518
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 77us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.606598
last_received_ts = 497.605804
last_seq = 5726
current_ts = 497.623260
current_received_ts = 497.622467
current_seq = 5727
count = 519
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 60us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.623260
last_received_ts = 497.622467
last_seq = 5727
current_ts = 497.639893
current_received_ts = 497.639099
current_seq = 5728
count = 520
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.639893
last_received_ts = 497.639099
last_seq = 5728
current_ts = 497.656555
current_received_ts = 497.655762
current_seq = 5729
count = 521
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.656555
last_received_ts = 497.655762
last_seq = 5729
current_ts = 497.673218
current_received_ts = 497.672455
current_seq = 5730
count = 522
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 44us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.673218
last_received_ts = 497.672455
last_seq = 5730
current_ts = 497.689880
current_received_ts = 497.689087
current_seq = 5731
count = 523
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 48us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.689880
last_received_ts = 497.689087
last_seq = 5731
current_ts = 497.706543
current_received_ts = 497.705780
current_seq = 5732
count = 524
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.706543
last_received_ts = 497.705780
last_seq = 5732
current_ts = 497.723206
current_received_ts = 497.722412
current_seq = 5733
count = 525
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 65us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.723206
last_received_ts = 497.722412
last_seq = 5733
current_ts = 497.739868
current_received_ts = 497.739075
current_seq = 5734
count = 526
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 56us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.739868
last_received_ts = 497.739075
last_seq = 5734
current_ts = 497.756500
current_received_ts = 497.755737
current_seq = 5735
count = 527
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.756500
last_received_ts = 497.755737
last_seq = 5735
current_ts = 497.773163
current_received_ts = 497.772369
current_seq = 5736
count = 528
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.773163
last_received_ts = 497.772369
last_seq = 5736
current_ts = 497.789825
current_received_ts = 497.789062
current_seq = 5737
count = 529
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.789825
last_received_ts = 497.789062
last_seq = 5737
current_ts = 497.806488
current_received_ts = 497.805725
current_seq = 5738
count = 530
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 80us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.806488
last_received_ts = 497.805725
last_seq = 5738
current_ts = 497.823151
current_received_ts = 497.822357
current_seq = 5739
count = 531
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 97us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.823151
last_received_ts = 497.822357
last_seq = 5739
current_ts = 497.839813
current_received_ts = 497.839020
current_seq = 5740
count = 532
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 69us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.839813
last_received_ts = 497.839020
last_seq = 5740
current_ts = 497.856476
current_received_ts = 497.855682
current_seq = 5741
count = 533
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 98us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.856476
last_received_ts = 497.855682
last_seq = 5741
current_ts = 497.873138
current_received_ts = 497.872314
current_seq = 5742
count = 534
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 43us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.873138
last_received_ts = 497.872314
last_seq = 5742
current_ts = 497.889771
current_received_ts = 497.889008
current_seq = 5743
count = 535
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 57us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.889771
last_received_ts = 497.889008
last_seq = 5743
current_ts = 497.906433
current_received_ts = 497.905670
current_seq = 5744
count = 536
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 51us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.906433
last_received_ts = 497.905670
last_seq = 5744
current_ts = 497.923096
current_received_ts = 497.922302
current_seq = 5745
count = 537
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 51us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.923096
last_received_ts = 497.922302
last_seq = 5745
current_ts = 497.939758
current_received_ts = 497.938965
current_seq = 5746
count = 538
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 81us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.939758
last_received_ts = 497.938965
last_seq = 5746
current_ts = 497.956421
current_received_ts = 497.955627
current_seq = 5747
count = 539
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 55us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.956421
last_received_ts = 497.955627
last_seq = 5747
current_ts = 497.973083
current_received_ts = 497.972260
current_seq = 5748
count = 540
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 62us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.973083
last_received_ts = 497.972260
last_seq = 5748
current_ts = 497.989746
current_received_ts = 497.988922
current_seq = 5749
count = 541
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 55us
(kms_flip:9513) DEBUG: name = flip
last_ts = 497.989746
last_received_ts = 497.988922
last_seq = 5749
current_ts = 498.006409
current_received_ts = 498.005646
current_seq = 5750
count = 542
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 93us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.006409
last_received_ts = 498.005646
last_seq = 5750
current_ts = 498.023041
current_received_ts = 498.022247
current_seq = 5751
count = 543
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 41us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.023041
last_received_ts = 498.022247
last_seq = 5751
current_ts = 498.039703
current_received_ts = 498.038940
current_seq = 5752
count = 544
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 57us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.039703
last_received_ts = 498.038940
last_seq = 5752
current_ts = 498.056366
current_received_ts = 498.055603
current_seq = 5753
count = 545
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 40us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.056366
last_received_ts = 498.055603
last_seq = 5753
current_ts = 498.073029
current_received_ts = 498.072235
current_seq = 5754
count = 546
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 58us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.073029
last_received_ts = 498.072235
last_seq = 5754
current_ts = 498.089691
current_received_ts = 498.088898
current_seq = 5755
count = 547
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.089691
last_received_ts = 498.088898
last_seq = 5755
current_ts = 498.106354
current_received_ts = 498.105743
current_seq = 5756
count = 548
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 76us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.106354
last_received_ts = 498.105743
last_seq = 5756
current_ts = 498.123016
current_received_ts = 498.122223
current_seq = 5757
count = 549
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 65us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.123016
last_received_ts = 498.122223
last_seq = 5757
current_ts = 498.139679
current_received_ts = 498.138855
current_seq = 5758
count = 550
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 66us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.139679
last_received_ts = 498.138855
last_seq = 5758
current_ts = 498.156311
current_received_ts = 498.155548
current_seq = 5759
count = 551
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 86us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.156311
last_received_ts = 498.155548
last_seq = 5759
current_ts = 498.172974
current_received_ts = 498.172180
current_seq = 5760
count = 552
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 55us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.172974
last_received_ts = 498.172180
last_seq = 5760
current_ts = 498.189636
current_received_ts = 498.188843
current_seq = 5761
count = 553
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.189636
last_received_ts = 498.188843
last_seq = 5761
current_ts = 498.206299
current_received_ts = 498.205505
current_seq = 5762
count = 554
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.206299
last_received_ts = 498.205505
last_seq = 5762
current_ts = 498.222961
current_received_ts = 498.222168
current_seq = 5763
count = 555
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 44us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.222961
last_received_ts = 498.222168
last_seq = 5763
current_ts = 498.239624
current_received_ts = 498.238831
current_seq = 5764
count = 556
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.239624
last_received_ts = 498.238831
last_seq = 5764
current_ts = 498.256256
current_received_ts = 498.255493
current_seq = 5765
count = 557
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 41us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.256256
last_received_ts = 498.255493
last_seq = 5765
current_ts = 498.272949
current_received_ts = 498.272125
current_seq = 5766
count = 558
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.272949
last_received_ts = 498.272125
last_seq = 5766
current_ts = 498.289581
current_received_ts = 498.288818
current_seq = 5767
count = 559
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 51us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.289581
last_received_ts = 498.288818
last_seq = 5767
current_ts = 498.306244
current_received_ts = 498.305481
current_seq = 5768
count = 560
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 59us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.306244
last_received_ts = 498.305481
last_seq = 5768
current_ts = 498.322906
current_received_ts = 498.322113
current_seq = 5769
count = 561
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 42us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.322906
last_received_ts = 498.322113
last_seq = 5769
current_ts = 498.339569
current_received_ts = 498.338776
current_seq = 5770
count = 562
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 58us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.339569
last_received_ts = 498.338776
last_seq = 5770
current_ts = 498.356232
current_received_ts = 498.355438
current_seq = 5771
count = 563
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 57us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.356232
last_received_ts = 498.355438
last_seq = 5771
current_ts = 498.372894
current_received_ts = 498.372101
current_seq = 5772
count = 564
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 58us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.372894
last_received_ts = 498.372101
last_seq = 5772
current_ts = 498.389526
current_received_ts = 498.388763
current_seq = 5773
count = 565
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 52us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.389526
last_received_ts = 498.388763
last_seq = 5773
current_ts = 498.406189
current_received_ts = 498.405396
current_seq = 5774
count = 566
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.406189
last_received_ts = 498.405396
last_seq = 5774
current_ts = 498.422852
current_received_ts = 498.422089
current_seq = 5775
count = 567
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 89us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.422852
last_received_ts = 498.422089
last_seq = 5775
current_ts = 498.439514
current_received_ts = 498.438751
current_seq = 5776
count = 568
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 68us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.439514
last_received_ts = 498.438751
last_seq = 5776
current_ts = 498.456177
current_received_ts = 498.455383
current_seq = 5777
count = 569
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 77us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.456177
last_received_ts = 498.455383
last_seq = 5777
current_ts = 498.472839
current_received_ts = 498.472076
current_seq = 5778
count = 570
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 59us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.472839
last_received_ts = 498.472076
last_seq = 5778
current_ts = 498.489502
current_received_ts = 498.488708
current_seq = 5779
count = 571
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 54us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.489502
last_received_ts = 498.488708
last_seq = 5779
current_ts = 498.506165
current_received_ts = 498.505371
current_seq = 5780
count = 572
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 61us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.506165
last_received_ts = 498.505371
last_seq = 5780
current_ts = 498.522797
current_received_ts = 498.522034
current_seq = 5781
count = 573
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 58us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.522797
last_received_ts = 498.522034
last_seq = 5781
current_ts = 498.539459
current_received_ts = 498.538666
current_seq = 5782
count = 574
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 56us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.539459
last_received_ts = 498.538666
last_seq = 5782
current_ts = 498.556122
current_received_ts = 498.555359
current_seq = 5783
count = 575
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 122us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.556122
last_received_ts = 498.555359
last_seq = 5783
current_ts = 498.572784
current_received_ts = 498.572021
current_seq = 5784
count = 576
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.572784
last_received_ts = 498.572021
last_seq = 5784
current_ts = 498.589447
current_received_ts = 498.588654
current_seq = 5785
count = 577
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 56us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.589447
last_received_ts = 498.588654
last_seq = 5785
current_ts = 498.606110
current_received_ts = 498.605286
current_seq = 5786
count = 578
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 53us
(kms_flip:9513) DEBUG: name = flip
last_ts = 498.606110
last_received_ts = 498.605286
last_seq = 5786
current_ts = 498.622772
current_received_ts = 498.621979
current_seq = 5787
count = 579
seq_step = 1
(kms_flip:9513) DEBUG: Vblank took 743us
(kms_flip:9513) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:9513) CRITICAL: Failed assertion: end - start < 500
(kms_flip:9513) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:9513) igt_core-INFO: Stack trace:
(kms_flip:9513) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:9513) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:9513) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:9513) igt_core-INFO:   #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
(kms_flip:9513) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:9513) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:9513) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:9513) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (10.951s)

Dmesg

<6> [595.162310] Console: switching to colour dummy device 80x25

<6> [595.162602] [IGT] kms_flip: executing

<7> [595.168092] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1]

<7> [595.168101] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1]

<7> [595.168546] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4

<7> [595.168636] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected

<7> [595.168865] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2]

<7> [595.168867] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2]

<7> [595.168979] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4

<7> [595.169062] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected

<7> [595.169299] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3]

<7> [595.169301] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3]

<7> [595.169435] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4

<7> [595.169531] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected

<7> [595.169795] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1]

<7> [595.169797] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:392:eDP-1]

<7> [595.169895] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on

<7> [595.169997] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f

<7> [595.170416] 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> [595.170727] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000

<7> [595.170831] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000

<7> [595.170934] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000

<7> [595.171053] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz

<5> [595.171057] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [595.171058] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [595.171059] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] DisplayID extension version 0x13, primary use 0x00

<7> [595.171061] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc.

<5> [595.171063] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [595.171064] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD monitor

<5> [595.171066] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [595.171067] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD size 20, SAD count 0

<5> [595.171069] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [595.171081] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] VRR capable: yes

<7> [595.171159] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps

<7> [595.171258] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no

<5> [595.171791] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [595.171793] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [595.171794] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [595.171849] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] probed modes:

<7> [595.171851] 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> [595.171854] 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> [595.171866] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1]

<7> [595.171869] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1]

<7> [595.172016] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected

<7> [595.172027] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2]

<7> [595.172029] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2]

<7> [595.172144] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected

<7> [595.172150] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3]

<7> [595.172152] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3]

<7> [595.172382] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected

<6> [595.175788] [IGT] kms_flip: starting subtest flip-vs-expired-vblank-interruptible

<6> [595.177105] [IGT] kms_flip: starting dynamic subtest A-eDP1

<7> [595.187057] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:428]

<7> [595.187502] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:437]

<7> [595.238118] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

<7> [595.238209] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected yes, found no)

<7> [595.238389] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected yes, found no)

<7> [595.238511] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)

<7> [595.238607] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 4, found 0)

<7> [595.238700] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150: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> [595.238790] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)

<7> [595.238879] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)

<7> [595.238971] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)

<7> [595.239062] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)

<7> [595.239151] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)

<7> [595.239247] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)

<7> [595.239354] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)

<7> [595.239465] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)

<7> [595.239561] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)

<7> [595.239642] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)

<7> [595.239721] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)

<7> [595.239799] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)

<7> [595.239875] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)

<7> [595.239951] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)

<7> [595.240026] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)

<7> [595.240100] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)

<7> [595.240180] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)

<7> [595.240271] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)

<7> [595.240370] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)

<7> [595.240462] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)

<7> [595.240541] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)

<7> [595.240613] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)

<7> [595.240684] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)

<7> [595.240762] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)

<7> [595.240839] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)

<7> [595.240917] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)

<7> [595.240995] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)

<7> [595.241066] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)

<7> [595.241136] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)

<7> [595.241208] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)

<7> [595.241335] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)

<7> [595.241440] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)

<7> [595.241539] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 432000, found 0)

<7> [595.241620] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset

<7> [595.241697] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:150:pipe A] releasing DPLL 0

<7> [595.241799] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no

<7> [595.241865] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0

<7> [595.241938] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0

<7> [595.241993] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0

<7> [595.242049] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm

<7> [595.242103] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.242157] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.242210] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.242313] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 0 num active planes 0

<7> [595.242437] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400

<7> [595.242545] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400

<7> [595.242626] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400

<7> [595.242708] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400

<7> [595.242795] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0

<7> [595.242880] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 173855 kHz -> 0 kHz

<7> [595.242993] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz

<7> [595.243074] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing

<7> [595.243149] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz

<7> [595.243233] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0

<7> [595.243363] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: no [modeset]

<7> [595.243471] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [NOFB], visible: no

<7> [595.243562] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no

<7> [595.243638] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no

<7> [595.243712] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no

<7> [595.243786] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no

<7> [595.243858] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no

<7> [595.243986] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off

<7> [595.244077] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00

<7> [595.244206] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2

<7> [595.263968] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM

<7> [595.264533] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]

<7> [595.466460] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 0

<7> [595.467006] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A

<7> [595.477790] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power off

<7> [595.478147] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power off time

<7> [595.478247] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000

<7> [595.478545] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060

<7> [595.478681] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short

<7> [595.529577] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [595.529995] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:150:pipe A]

<7> [595.530047] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A]

<7> [595.530528] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000

<7> [595.530850] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short

<7> [595.531198] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A]

<7> [595.531560] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0

<7> [595.532043] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A

<7> [595.532577] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A]

<7> [595.532948] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1]

<7> [595.533261] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A]

<7> [595.533671] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B]

<7> [595.533970] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C]

<7> [595.534268] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2]

<7> [595.534601] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A]

<7> [595.534880] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B]

<7> [595.535155] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C]

<7> [595.535458] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3]

<7> [595.535755] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A]

<7> [595.536049] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B]

<7> [595.536361] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C]

<7> [595.536627] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1]

<7> [595.537009] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [595.537278] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)

<7> [595.537610] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1

<7> [595.538146] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A

<7> [595.538603] 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> [595.539060] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A]

<7> [595.539400] 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> [595.539861] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [595.540148] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384

<7> [595.541037] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]

<7> [595.541432] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:388:pipe C]

<7> [595.541767] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

<7> [595.541839] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:392:eDP-1]

<7> [595.542022] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:392:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)

<7> [595.542473] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:391:DDI A/PHY A][CRTC:150: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> [595.542807] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000

<7> [595.543135] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0

<7> [595.543480] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:391:DDI A/PHY A] [CRTC:150:pipe A]

<7> [595.543801] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes)

<7> [595.544138] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes)

<7> [595.544445] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)

<7> [595.544744] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4)

<7> [595.545005] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)

<7> [595.545260] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)

<7> [595.545577] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)

<7> [595.545813] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)

<7> [595.546029] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)

<7> [595.546274] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)

<7> [595.546518] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)

<7> [595.546730] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)

<7> [595.546915] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)

<7> [595.547099] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)

<7> [595.547274] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)

<7> [595.547502] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)

<7> [595.547667] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)

<7> [595.547829] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)

<7> [595.547983] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)

<7> [595.548136] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)

<7> [595.548285] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)

<7> [595.548455] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)

<7> [595.548601] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)

<7> [595.548743] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)

<7> [595.548877] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)

<7> [595.549009] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)

<7> [595.549140] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)

<7> [595.549266] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)

<7> [595.549413] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)

<7> [595.549543] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)

<7> [595.549670] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)

<7> [595.549795] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)

<7> [595.549921] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)

<7> [595.550039] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)

<7> [595.550156] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)

<7> [595.550266] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)

<7> [595.550392] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)

<7> [595.550501] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)

<7> [595.550610] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset

<7> [595.550770] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes

<7> [595.550863] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1

<7> [595.551001] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051

<7> [595.551077] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45

<7> [595.551153] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm

<7> [595.551228] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.551300] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.551394] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [595.551484] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 1390840 num active planes 1

<7> [595.551611] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400

<7> [595.551719] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400

<7> [595.551819] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400

<7> [595.551915] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400

<7> [595.552009] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461

<7> [595.552101] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 173855 kHz

<7> [595.552210] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz

<7> [595.552303] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing

<7> [595.552419] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz

<7> [595.552522] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0

<7> [595.552634] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated DPLL 0

<7> [595.552727] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving DPLL 0

<7> [595.552810] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset]

<7> [595.552894] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB

<7> [595.552979] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0

<7> [595.553060] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>

<7> [595.553135] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0

<7> [595.553209] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0

<7> [595.553282] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0

<7> [595.553408] 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> [595.553507] 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> [595.553604] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled

<7> [595.553681] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled

<7> [595.553755] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled

<7> [595.553828] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0

<7> [595.553902] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4

<7> [595.553976] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14

<7> [595.554049] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB

<7> [595.554124] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB

<7> [595.554197] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0

<7> [595.554269] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range

<7> [595.554359] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined

<7> [595.554455] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1

<7> [595.554550] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0

<7> [595.554645] 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> [595.554725] 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> [595.554801] 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> [595.554875] 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> [595.554950] 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> [595.555024] 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> [595.555097] 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> [595.555170] 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> [595.555242] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855

<7> [595.555325] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0

<7> [595.555432] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0

<7> [595.555538] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no

<7> [595.555629] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0

<7> [595.555701] 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> [595.555772] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,

<7> [595.555842] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.

<7> [595.555914] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:

<7> [595.555990] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21

<7> [595.556066] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1

<7> [595.556141] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0

<7> [595.556216] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0

<7> [595.556284] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1

<7> [595.556372] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23

<7> [595.556475] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0

<7> [595.556579] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries

<7> [595.556672] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000

<7> [595.556752] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [595.556822] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [595.556893] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [595.556975] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000

<7> [595.557061] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000

<7> [595.557147] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [595.557228] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [595.557297] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [595.557394] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000

<7> [595.557488] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0

<7> [595.557581] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [FB:428] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes

<7> [595.557663] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0

<7> [595.557735] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0

<7> [595.557807] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no

<7> [595.557878] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no

<7> [595.557948] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no

<7> [595.558018] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no

<7> [595.558088] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no

<7> [595.558446] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A

<7> [595.558609] 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> [595.558712] 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> [595.558806] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [595.558891] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480

<7> [595.558970] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A]

<7> [595.559034] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1]

<7> [595.559098] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A]

<7> [595.559162] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B]

<7> [595.559225] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C]

<7> [595.559286] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2]

<7> [595.559366] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A]

<7> [595.559444] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B]

<7> [595.559520] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C]

<7> [595.559596] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3]

<7> [595.559661] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A]

<7> [595.559723] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B]

<7> [595.559784] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C]

<7> [595.559866] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf

<7> [595.560021] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)

<7> [595.560079] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)

<7> [595.560181] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A

<7> [595.561432] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:150:pipe A]

<7> [595.561562] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0

<7> [595.563531] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power on

<7> [595.563629] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining)

<7> [595.566879] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010

<7> [595.566998] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long

<7> [595.567084] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10

<7> [595.567179] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A]

<7> [596.034671] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060

<7> [596.136411] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [596.136843] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power on

<7> [596.137176] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063

<7> [596.173181] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010

<7> [596.173809] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long

<7> [596.174292] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20

<7> [596.174777] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A]

<7> [596.210694] 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> [596.210707] 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> [596.210836] 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> [596.349998] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [596.350428] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on

<7> [596.350899] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b

<7> [596.353160] 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> [596.354735] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Reloading eDP link rates

<7> [596.355589] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05

<7> [596.356809] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0

<7> [596.358236] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS1

<7> [596.359383] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Clock recovery OK

<7> [596.359787] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS4

<7> [596.361313] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful

<7> [596.361675] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4

<7> [596.362467] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A

<7> [596.363036] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]

<7> [596.363463] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A

<7> [596.363919] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 4518

<7> [596.379783] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2

<7> [596.381438] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1]

<7> [596.381842] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A]

<7> [598.900412] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD off

<7> [598.900946] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067

<7> [606.078707] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off

<7> [606.079063] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6

<7> [606.079318] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02

<6> [606.129215] [IGT] kms_flip: finished subtest A-eDP1, FAIL

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