igt@kms_flip@flip-vs-expired-vblank-interruptible@a-edp1 on shard-lnl@xe-4339-77ca0c5f244b2796408d20cf3c0741094304e09f Test details

Detail	Value
Duration	8.98 seconds
Hostname	shard-lnl-8
Igt-Version	IGT-Version: 2.3-g653d1b1eb (x86_64) (Linux: 6.19.0-rc4-lgci-xe-xe-4339-77ca0c5f244b27964+ x86_64)
Out	Using IGT_SRANDOM=1767798583 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:923 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1889 run_test() #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045() #4 ../tests/kms_flip.c:2045 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (8.977s)
Err	Starting subtest: flip-vs-expired-vblank-interruptible Starting dynamic subtest: A-eDP1 (kms_flip:5379) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:5379) CRITICAL: Failed assertion: end - start < 500 (kms_flip:5379) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:5379) DEBUG: Vblank took 38us (kms_flip:5379) DEBUG: name = flip last_ts = 250.438385 last_received_ts = 250.437607 last_seq = 2768 current_ts = 250.455063 current_received_ts = 250.454239 current_seq = 2769 count = 344 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 39us (kms_flip:5379) DEBUG: name = flip last_ts = 250.455063 last_received_ts = 250.454239 last_seq = 2769 current_ts = 250.471725 current_received_ts = 250.470947 current_seq = 2770 count = 345 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 118us (kms_flip:5379) DEBUG: name = flip last_ts = 250.471725 last_received_ts = 250.470947 last_seq = 2770 current_ts = 250.488388 current_received_ts = 250.487610 current_seq = 2771 count = 346 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 250.488388 last_received_ts = 250.487610 last_seq = 2771 current_ts = 250.505051 current_received_ts = 250.504318 current_seq = 2772 count = 347 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 106us (kms_flip:5379) DEBUG: name = flip last_ts = 250.505051 last_received_ts = 250.504318 last_seq = 2772 current_ts = 250.521713 current_received_ts = 250.520920 current_seq = 2773 count = 348 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 105us (kms_flip:5379) DEBUG: name = flip last_ts = 250.521713 last_received_ts = 250.520920 last_seq = 2773 current_ts = 250.538376 current_received_ts = 250.537598 current_seq = 2774 count = 349 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 126us (kms_flip:5379) DEBUG: name = flip last_ts = 250.538376 last_received_ts = 250.537598 last_seq = 2774 current_ts = 250.555038 current_received_ts = 250.554245 current_seq = 2775 count = 350 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 82us (kms_flip:5379) DEBUG: name = flip last_ts = 250.555038 last_received_ts = 250.554245 last_seq = 2775 current_ts = 250.571701 current_received_ts = 250.570892 current_seq = 2776 count = 351 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 69us (kms_flip:5379) DEBUG: name = flip last_ts = 250.571701 last_received_ts = 250.570892 last_seq = 2776 current_ts = 250.588364 current_received_ts = 250.587570 current_seq = 2777 count = 352 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 67us (kms_flip:5379) DEBUG: name = flip last_ts = 250.588364 last_received_ts = 250.587570 last_seq = 2777 current_ts = 250.605042 current_received_ts = 250.604218 current_seq = 2778 count = 353 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 65us (kms_flip:5379) DEBUG: name = flip last_ts = 250.605042 last_received_ts = 250.604218 last_seq = 2778 current_ts = 250.621689 current_received_ts = 250.620895 current_seq = 2779 count = 354 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 66us (kms_flip:5379) DEBUG: name = flip last_ts = 250.621689 last_received_ts = 250.620895 last_seq = 2779 current_ts = 250.638351 current_received_ts = 250.637558 current_seq = 2780 count = 355 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 67us (kms_flip:5379) DEBUG: name = flip last_ts = 250.638351 last_received_ts = 250.637558 last_seq = 2780 current_ts = 250.655029 current_received_ts = 250.654205 current_seq = 2781 count = 356 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 65us (kms_flip:5379) DEBUG: name = flip last_ts = 250.655029 last_received_ts = 250.654205 last_seq = 2781 current_ts = 250.671692 current_received_ts = 250.670944 current_seq = 2782 count = 357 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 182us (kms_flip:5379) DEBUG: name = flip last_ts = 250.671692 last_received_ts = 250.670944 last_seq = 2782 current_ts = 250.688354 current_received_ts = 250.687561 current_seq = 2783 count = 358 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 69us (kms_flip:5379) DEBUG: name = flip last_ts = 250.688354 last_received_ts = 250.687561 last_seq = 2783 current_ts = 250.705017 current_received_ts = 250.704224 current_seq = 2784 count = 359 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 79us (kms_flip:5379) DEBUG: name = flip last_ts = 250.705017 last_received_ts = 250.704224 last_seq = 2784 current_ts = 250.721680 current_received_ts = 250.720901 current_seq = 2785 count = 360 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 56us (kms_flip:5379) DEBUG: name = flip last_ts = 250.721680 last_received_ts = 250.720901 last_seq = 2785 current_ts = 250.738342 current_received_ts = 250.737564 current_seq = 2786 count = 361 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 49us (kms_flip:5379) DEBUG: name = flip last_ts = 250.738342 last_received_ts = 250.737564 last_seq = 2786 current_ts = 250.755005 current_received_ts = 250.754211 current_seq = 2787 count = 362 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 53us (kms_flip:5379) DEBUG: name = flip last_ts = 250.755005 last_received_ts = 250.754211 last_seq = 2787 current_ts = 250.771667 current_received_ts = 250.770889 current_seq = 2788 count = 363 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 52us (kms_flip:5379) DEBUG: name = flip last_ts = 250.771667 last_received_ts = 250.770889 last_seq = 2788 current_ts = 250.788345 current_received_ts = 250.787552 current_seq = 2789 count = 364 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 51us (kms_flip:5379) DEBUG: name = flip last_ts = 250.788345 last_received_ts = 250.787552 last_seq = 2789 current_ts = 250.805008 current_received_ts = 250.804214 current_seq = 2790 count = 365 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 51us (kms_flip:5379) DEBUG: name = flip last_ts = 250.805008 last_received_ts = 250.804214 last_seq = 2790 current_ts = 250.821671 current_received_ts = 250.820892 current_seq = 2791 count = 366 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 48us (kms_flip:5379) DEBUG: name = flip last_ts = 250.821671 last_received_ts = 250.820892 last_seq = 2791 current_ts = 250.838333 current_received_ts = 250.837555 current_seq = 2792 count = 367 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 48us (kms_flip:5379) DEBUG: name = flip last_ts = 250.838333 last_received_ts = 250.837555 last_seq = 2792 current_ts = 250.854996 current_received_ts = 250.854187 current_seq = 2793 count = 368 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 57us (kms_flip:5379) DEBUG: name = flip last_ts = 250.854996 last_received_ts = 250.854187 last_seq = 2793 current_ts = 250.871658 current_received_ts = 250.870880 current_seq = 2794 count = 369 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 48us (kms_flip:5379) DEBUG: name = flip last_ts = 250.871658 last_received_ts = 250.870880 last_seq = 2794 current_ts = 250.888321 current_received_ts = 250.887543 current_seq = 2795 count = 370 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 43us (kms_flip:5379) DEBUG: name = flip last_ts = 250.888321 last_received_ts = 250.887543 last_seq = 2795 current_ts = 250.904984 current_received_ts = 250.904175 current_seq = 2796 count = 371 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 39us (kms_flip:5379) DEBUG: name = flip last_ts = 250.904984 last_received_ts = 250.904175 last_seq = 2796 current_ts = 250.921646 current_received_ts = 250.920883 current_seq = 2797 count = 372 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 98us (kms_flip:5379) DEBUG: name = flip last_ts = 250.921646 last_received_ts = 250.920883 last_seq = 2797 current_ts = 250.938309 current_received_ts = 250.937531 current_seq = 2798 count = 373 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 117us (kms_flip:5379) DEBUG: name = flip last_ts = 250.938309 last_received_ts = 250.937531 last_seq = 2798 current_ts = 250.954987 current_received_ts = 250.954178 current_seq = 2799 count = 374 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 40us (kms_flip:5379) DEBUG: name = flip last_ts = 250.954987 last_received_ts = 250.954178 last_seq = 2799 current_ts = 250.971649 current_received_ts = 250.970856 current_seq = 2800 count = 375 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 40us (kms_flip:5379) DEBUG: name = flip last_ts = 250.971649 last_received_ts = 250.970856 last_seq = 2800 current_ts = 250.988312 current_received_ts = 250.987534 current_seq = 2801 count = 376 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 250.988312 last_received_ts = 250.987534 last_seq = 2801 current_ts = 251.004974 current_received_ts = 251.004166 current_seq = 2802 count = 377 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 51us (kms_flip:5379) DEBUG: name = flip last_ts = 251.004974 last_received_ts = 251.004166 last_seq = 2802 current_ts = 251.021637 current_received_ts = 251.020828 current_seq = 2803 count = 378 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 48us (kms_flip:5379) DEBUG: name = flip last_ts = 251.021637 last_received_ts = 251.020828 last_seq = 2803 current_ts = 251.038300 current_received_ts = 251.037521 current_seq = 2804 count = 379 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 61us (kms_flip:5379) DEBUG: name = flip last_ts = 251.038300 last_received_ts = 251.037521 last_seq = 2804 current_ts = 251.054962 current_received_ts = 251.054169 current_seq = 2805 count = 380 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 55us (kms_flip:5379) DEBUG: name = flip last_ts = 251.054962 last_received_ts = 251.054169 last_seq = 2805 current_ts = 251.071625 current_received_ts = 251.070847 current_seq = 2806 count = 381 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 41us (kms_flip:5379) DEBUG: name = flip last_ts = 251.071625 last_received_ts = 251.070847 last_seq = 2806 current_ts = 251.088287 current_received_ts = 251.087509 current_seq = 2807 count = 382 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 251.088287 last_received_ts = 251.087509 last_seq = 2807 current_ts = 251.104950 current_received_ts = 251.104156 current_seq = 2808 count = 383 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 46us (kms_flip:5379) DEBUG: name = flip last_ts = 251.104950 last_received_ts = 251.104156 last_seq = 2808 current_ts = 251.121628 current_received_ts = 251.120834 current_seq = 2809 count = 384 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 47us (kms_flip:5379) DEBUG: name = flip last_ts = 251.121628 last_received_ts = 251.120834 last_seq = 2809 current_ts = 251.138290 current_received_ts = 251.137482 current_seq = 2810 count = 385 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 48us (kms_flip:5379) DEBUG: name = flip last_ts = 251.138290 last_received_ts = 251.137482 last_seq = 2810 current_ts = 251.154953 current_received_ts = 251.154160 current_seq = 2811 count = 386 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 251.154953 last_received_ts = 251.154160 last_seq = 2811 current_ts = 251.171616 current_received_ts = 251.170837 current_seq = 2812 count = 387 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 251.171616 last_received_ts = 251.170837 last_seq = 2812 current_ts = 251.188278 current_received_ts = 251.187500 current_seq = 2813 count = 388 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 48us (kms_flip:5379) DEBUG: name = flip last_ts = 251.188278 last_received_ts = 251.187500 last_seq = 2813 current_ts = 251.204941 current_received_ts = 251.204147 current_seq = 2814 count = 389 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 47us (kms_flip:5379) DEBUG: name = flip last_ts = 251.204941 last_received_ts = 251.204147 last_seq = 2814 current_ts = 251.221603 current_received_ts = 251.220810 current_seq = 2815 count = 390 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 43us (kms_flip:5379) DEBUG: name = flip last_ts = 251.221603 last_received_ts = 251.220810 last_seq = 2815 current_ts = 251.238266 current_received_ts = 251.237457 current_seq = 2816 count = 391 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 251.238266 last_received_ts = 251.237457 last_seq = 2816 current_ts = 251.254929 current_received_ts = 251.254135 current_seq = 2817 count = 392 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 251.254929 last_received_ts = 251.254135 last_seq = 2817 current_ts = 251.271591 current_received_ts = 251.270813 current_seq = 2818 count = 393 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 45us (kms_flip:5379) DEBUG: name = flip last_ts = 251.271591 last_received_ts = 251.270813 last_seq = 2818 current_ts = 251.288254 current_received_ts = 251.287476 current_seq = 2819 count = 394 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 251.288254 last_received_ts = 251.287476 last_seq = 2819 current_ts = 251.304932 current_received_ts = 251.304138 current_seq = 2820 count = 395 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 43us (kms_flip:5379) DEBUG: name = flip last_ts = 251.304932 last_received_ts = 251.304138 last_seq = 2820 current_ts = 251.321594 current_received_ts = 251.320816 current_seq = 2821 count = 396 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 251.321594 last_received_ts = 251.320816 last_seq = 2821 current_ts = 251.338257 current_received_ts = 251.337448 current_seq = 2822 count = 397 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 43us (kms_flip:5379) DEBUG: name = flip last_ts = 251.338257 last_received_ts = 251.337448 last_seq = 2822 current_ts = 251.354919 current_received_ts = 251.354111 current_seq = 2823 count = 398 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 57us (kms_flip:5379) DEBUG: name = flip last_ts = 251.354919 last_received_ts = 251.354111 last_seq = 2823 current_ts = 251.371582 current_received_ts = 251.370804 current_seq = 2824 count = 399 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 102us (kms_flip:5379) DEBUG: name = flip last_ts = 251.371582 last_received_ts = 251.370804 last_seq = 2824 current_ts = 251.388245 current_received_ts = 251.387466 current_seq = 2825 count = 400 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 46us (kms_flip:5379) DEBUG: name = flip last_ts = 251.388245 last_received_ts = 251.387466 last_seq = 2825 current_ts = 251.404907 current_received_ts = 251.404114 current_seq = 2826 count = 401 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 47us (kms_flip:5379) DEBUG: name = flip last_ts = 251.404907 last_received_ts = 251.404114 last_seq = 2826 current_ts = 251.421570 current_received_ts = 251.420792 current_seq = 2827 count = 402 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 54us (kms_flip:5379) DEBUG: name = flip last_ts = 251.421570 last_received_ts = 251.420792 last_seq = 2827 current_ts = 251.438232 current_received_ts = 251.437469 current_seq = 2828 count = 403 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 52us (kms_flip:5379) DEBUG: name = flip last_ts = 251.438232 last_received_ts = 251.437469 last_seq = 2828 current_ts = 251.454910 current_received_ts = 251.454102 current_seq = 2829 count = 404 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 43us (kms_flip:5379) DEBUG: name = flip last_ts = 251.454910 last_received_ts = 251.454102 last_seq = 2829 current_ts = 251.471573 current_received_ts = 251.470795 current_seq = 2830 count = 405 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 58us (kms_flip:5379) DEBUG: name = flip last_ts = 251.471573 last_received_ts = 251.470795 last_seq = 2830 current_ts = 251.488235 current_received_ts = 251.487442 current_seq = 2831 count = 406 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 54us (kms_flip:5379) DEBUG: name = flip last_ts = 251.488235 last_received_ts = 251.487442 last_seq = 2831 current_ts = 251.504898 current_received_ts = 251.504105 current_seq = 2832 count = 407 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 251.504898 last_received_ts = 251.504105 last_seq = 2832 current_ts = 251.521561 current_received_ts = 251.520782 current_seq = 2833 count = 408 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 48us (kms_flip:5379) DEBUG: name = flip last_ts = 251.521561 last_received_ts = 251.520782 last_seq = 2833 current_ts = 251.538223 current_received_ts = 251.537445 current_seq = 2834 count = 409 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 251.538223 last_received_ts = 251.537445 last_seq = 2834 current_ts = 251.554886 current_received_ts = 251.554092 current_seq = 2835 count = 410 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 47us (kms_flip:5379) DEBUG: name = flip last_ts = 251.554886 last_received_ts = 251.554092 last_seq = 2835 current_ts = 251.571548 current_received_ts = 251.570740 current_seq = 2836 count = 411 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 47us (kms_flip:5379) DEBUG: name = flip last_ts = 251.571548 last_received_ts = 251.570740 last_seq = 2836 current_ts = 251.588226 current_received_ts = 251.587433 current_seq = 2837 count = 412 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 251.588226 last_received_ts = 251.587433 last_seq = 2837 current_ts = 251.604874 current_received_ts = 251.604080 current_seq = 2838 count = 413 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 50us (kms_flip:5379) DEBUG: name = flip last_ts = 251.604874 last_received_ts = 251.604080 last_seq = 2838 current_ts = 251.621552 current_received_ts = 251.620758 current_seq = 2839 count = 414 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 47us (kms_flip:5379) DEBUG: name = flip last_ts = 251.621552 last_received_ts = 251.620758 last_seq = 2839 current_ts = 251.638214 current_received_ts = 251.637421 current_seq = 2840 count = 415 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 51us (kms_flip:5379) DEBUG: name = flip last_ts = 251.638214 last_received_ts = 251.637421 last_seq = 2840 current_ts = 251.654877 current_received_ts = 251.654266 current_seq = 2841 count = 416 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 110us (kms_flip:5379) DEBUG: name = flip last_ts = 251.654877 last_received_ts = 251.654266 last_seq = 2841 current_ts = 251.671539 current_received_ts = 251.670761 current_seq = 2842 count = 417 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 120us (kms_flip:5379) DEBUG: name = flip last_ts = 251.671539 last_received_ts = 251.670761 last_seq = 2842 current_ts = 251.688202 current_received_ts = 251.687408 current_seq = 2843 count = 418 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 70us (kms_flip:5379) DEBUG: name = flip last_ts = 251.688202 last_received_ts = 251.687408 last_seq = 2843 current_ts = 251.704865 current_received_ts = 251.704071 current_seq = 2844 count = 419 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 58us (kms_flip:5379) DEBUG: name = flip last_ts = 251.704865 last_received_ts = 251.704071 last_seq = 2844 current_ts = 251.721527 current_received_ts = 251.720749 current_seq = 2845 count = 420 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 66us (kms_flip:5379) DEBUG: name = flip last_ts = 251.721527 last_received_ts = 251.720749 last_seq = 2845 current_ts = 251.738205 current_received_ts = 251.737411 current_seq = 2846 count = 421 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 53us (kms_flip:5379) DEBUG: name = flip last_ts = 251.738205 last_received_ts = 251.737411 last_seq = 2846 current_ts = 251.754852 current_received_ts = 251.754074 current_seq = 2847 count = 422 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 52us (kms_flip:5379) DEBUG: name = flip last_ts = 251.754852 last_received_ts = 251.754074 last_seq = 2847 current_ts = 251.771515 current_received_ts = 251.770737 current_seq = 2848 count = 423 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 251.771515 last_received_ts = 251.770737 last_seq = 2848 current_ts = 251.788193 current_received_ts = 251.787399 current_seq = 2849 count = 424 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 251.788193 last_received_ts = 251.787399 last_seq = 2849 current_ts = 251.804855 current_received_ts = 251.804047 current_seq = 2850 count = 425 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 251.804855 last_received_ts = 251.804047 last_seq = 2850 current_ts = 251.821518 current_received_ts = 251.820740 current_seq = 2851 count = 426 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 46us (kms_flip:5379) DEBUG: name = flip last_ts = 251.821518 last_received_ts = 251.820740 last_seq = 2851 current_ts = 251.838181 current_received_ts = 251.837387 current_seq = 2852 count = 427 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 43us (kms_flip:5379) DEBUG: name = flip last_ts = 251.838181 last_received_ts = 251.837387 last_seq = 2852 current_ts = 251.854843 current_received_ts = 251.854065 current_seq = 2853 count = 428 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 50us (kms_flip:5379) DEBUG: name = flip last_ts = 251.854843 last_received_ts = 251.854065 last_seq = 2853 current_ts = 251.871506 current_received_ts = 251.870728 current_seq = 2854 count = 429 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 49us (kms_flip:5379) DEBUG: name = flip last_ts = 251.871506 last_received_ts = 251.870728 last_seq = 2854 current_ts = 251.888168 current_received_ts = 251.887375 current_seq = 2855 count = 430 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 251.888168 last_received_ts = 251.887375 last_seq = 2855 current_ts = 251.904831 current_received_ts = 251.904068 current_seq = 2856 count = 431 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 56us (kms_flip:5379) DEBUG: name = flip last_ts = 251.904831 last_received_ts = 251.904068 last_seq = 2856 current_ts = 251.921509 current_received_ts = 251.920685 current_seq = 2857 count = 432 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 251.921509 last_received_ts = 251.920685 last_seq = 2857 current_ts = 251.938171 current_received_ts = 251.937378 current_seq = 2858 count = 433 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 61us (kms_flip:5379) DEBUG: name = flip last_ts = 251.938171 last_received_ts = 251.937378 last_seq = 2858 current_ts = 251.954834 current_received_ts = 251.954056 current_seq = 2859 count = 434 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 51us (kms_flip:5379) DEBUG: name = flip last_ts = 251.954834 last_received_ts = 251.954056 last_seq = 2859 current_ts = 251.971497 current_received_ts = 251.970718 current_seq = 2860 count = 435 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 50us (kms_flip:5379) DEBUG: name = flip last_ts = 251.971497 last_received_ts = 251.970718 last_seq = 2860 current_ts = 251.988159 current_received_ts = 251.987366 current_seq = 2861 count = 436 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 51us (kms_flip:5379) DEBUG: name = flip last_ts = 251.988159 last_received_ts = 251.987366 last_seq = 2861 current_ts = 252.004822 current_received_ts = 252.004059 current_seq = 2862 count = 437 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 48us (kms_flip:5379) DEBUG: name = flip last_ts = 252.004822 last_received_ts = 252.004059 last_seq = 2862 current_ts = 252.021484 current_received_ts = 252.020706 current_seq = 2863 count = 438 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 252.021484 last_received_ts = 252.020706 last_seq = 2863 current_ts = 252.038147 current_received_ts = 252.037354 current_seq = 2864 count = 439 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 53us (kms_flip:5379) DEBUG: name = flip last_ts = 252.038147 last_received_ts = 252.037354 last_seq = 2864 current_ts = 252.054810 current_received_ts = 252.054047 current_seq = 2865 count = 440 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 82us (kms_flip:5379) DEBUG: name = flip last_ts = 252.054810 last_received_ts = 252.054047 last_seq = 2865 current_ts = 252.071472 current_received_ts = 252.070709 current_seq = 2866 count = 441 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 50us (kms_flip:5379) DEBUG: name = flip last_ts = 252.071472 last_received_ts = 252.070709 last_seq = 2866 current_ts = 252.088135 current_received_ts = 252.087357 current_seq = 2867 count = 442 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 56us (kms_flip:5379) DEBUG: name = flip last_ts = 252.088135 last_received_ts = 252.087357 last_seq = 2867 current_ts = 252.104797 current_received_ts = 252.104050 current_seq = 2868 count = 443 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 56us (kms_flip:5379) DEBUG: name = flip last_ts = 252.104797 last_received_ts = 252.104050 last_seq = 2868 current_ts = 252.121475 current_received_ts = 252.120697 current_seq = 2869 count = 444 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 54us (kms_flip:5379) DEBUG: name = flip last_ts = 252.121475 last_received_ts = 252.120697 last_seq = 2869 current_ts = 252.138138 current_received_ts = 252.137329 current_seq = 2870 count = 445 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 42us (kms_flip:5379) DEBUG: name = flip last_ts = 252.138138 last_received_ts = 252.137329 last_seq = 2870 current_ts = 252.154800 current_received_ts = 252.154022 current_seq = 2871 count = 446 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 57us (kms_flip:5379) DEBUG: name = flip last_ts = 252.154800 last_received_ts = 252.154022 last_seq = 2871 current_ts = 252.171463 current_received_ts = 252.170685 current_seq = 2872 count = 447 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 49us (kms_flip:5379) DEBUG: name = flip last_ts = 252.171463 last_received_ts = 252.170685 last_seq = 2872 current_ts = 252.188126 current_received_ts = 252.187317 current_seq = 2873 count = 448 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 51us (kms_flip:5379) DEBUG: name = flip last_ts = 252.188126 last_received_ts = 252.187317 last_seq = 2873 current_ts = 252.204788 current_received_ts = 252.204025 current_seq = 2874 count = 449 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 252.204788 last_received_ts = 252.204025 last_seq = 2874 current_ts = 252.221451 current_received_ts = 252.220688 current_seq = 2875 count = 450 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 100us (kms_flip:5379) DEBUG: name = flip last_ts = 252.221451 last_received_ts = 252.220688 last_seq = 2875 current_ts = 252.238129 current_received_ts = 252.237320 current_seq = 2876 count = 451 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 94us (kms_flip:5379) DEBUG: name = flip last_ts = 252.238129 last_received_ts = 252.237320 last_seq = 2876 current_ts = 252.254791 current_received_ts = 252.253998 current_seq = 2877 count = 452 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 39us (kms_flip:5379) DEBUG: name = flip last_ts = 252.254791 last_received_ts = 252.253998 last_seq = 2877 current_ts = 252.271454 current_received_ts = 252.270630 current_seq = 2878 count = 453 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 41us (kms_flip:5379) DEBUG: name = flip last_ts = 252.271454 last_received_ts = 252.270630 last_seq = 2878 current_ts = 252.288116 current_received_ts = 252.287292 current_seq = 2879 count = 454 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 38us (kms_flip:5379) DEBUG: name = flip last_ts = 252.288116 last_received_ts = 252.287292 last_seq = 2879 current_ts = 252.304779 current_received_ts = 252.304001 current_seq = 2880 count = 455 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 41us (kms_flip:5379) DEBUG: name = flip last_ts = 252.304779 last_received_ts = 252.304001 last_seq = 2880 current_ts = 252.321442 current_received_ts = 252.320663 current_seq = 2881 count = 456 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 51us (kms_flip:5379) DEBUG: name = flip last_ts = 252.321442 last_received_ts = 252.320663 last_seq = 2881 current_ts = 252.338104 current_received_ts = 252.337296 current_seq = 2882 count = 457 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 54us (kms_flip:5379) DEBUG: name = flip last_ts = 252.338104 last_received_ts = 252.337296 last_seq = 2882 current_ts = 252.354767 current_received_ts = 252.353989 current_seq = 2883 count = 458 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 75us (kms_flip:5379) DEBUG: name = flip last_ts = 252.354767 last_received_ts = 252.353989 last_seq = 2883 current_ts = 252.371429 current_received_ts = 252.370651 current_seq = 2884 count = 459 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 252.371429 last_received_ts = 252.370651 last_seq = 2884 current_ts = 252.388092 current_received_ts = 252.387283 current_seq = 2885 count = 460 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 252.388092 last_received_ts = 252.387283 last_seq = 2885 current_ts = 252.404755 current_received_ts = 252.403992 current_seq = 2886 count = 461 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 90us (kms_flip:5379) DEBUG: name = flip last_ts = 252.404755 last_received_ts = 252.403992 last_seq = 2886 current_ts = 252.421417 current_received_ts = 252.420639 current_seq = 2887 count = 462 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 44us (kms_flip:5379) DEBUG: name = flip last_ts = 252.421417 last_received_ts = 252.420639 last_seq = 2887 current_ts = 252.438095 current_received_ts = 252.437286 current_seq = 2888 count = 463 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 49us (kms_flip:5379) DEBUG: name = flip last_ts = 252.438095 last_received_ts = 252.437286 last_seq = 2888 current_ts = 252.454758 current_received_ts = 252.453979 current_seq = 2889 count = 464 seq_step = 1 (kms_flip:5379) DEBUG: Vblank took 500us (kms_flip:5379) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:5379) CRITICAL: Failed assertion: end - start < 500 (kms_flip:5379) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:5379) igt_core-INFO: Stack trace: (kms_flip:5379) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:5379) igt_core-INFO: #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() (kms_flip:5379) igt_core-INFO: #2 ../tests/kms_flip.c:1889 run_test() (kms_flip:5379) igt_core-INFO: #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045() (kms_flip:5379) igt_core-INFO: #4 ../tests/kms_flip.c:2045 main() (kms_flip:5379) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:5379) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:5379) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (8.977s)
Dmesg	<6> [243.631704] Console: switching to colour dummy device 80x25 <6> [243.631965] [IGT] kms_flip: executing <7> [243.638300] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] <7> [243.638310] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:400:DP-1] <7> [243.638928] 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> [243.639021] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] disconnected <7> [243.639259] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] <7> [243.639262] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:412:DP-2] <7> [243.639383] 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> [243.639488] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] disconnected <7> [243.639744] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] <7> [243.639747] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:420:DP-3] <7> [243.639860] 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> [243.639945] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] disconnected <7> [243.640220] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:391:eDP-1] <7> [243.640224] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:391:eDP-1] <7> [243.640684] 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> [243.640992] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [243.641094] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [243.641193] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [243.641312] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz <5> [243.641316] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [243.641318] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [243.641318] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] DisplayID extension version 0x13, primary use 0x00 <7> [243.641320] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <5> [243.641322] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [243.641323] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] ELD monitor <5> [243.641325] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [243.641326] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] ELD size 20, SAD count 0 <5> [243.641327] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [243.641347] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:391:eDP-1] VRR capable: yes <7> [243.641455] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:391:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [243.641563] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:391:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <5> [243.642087] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [243.642089] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [243.642091] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [243.642149] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:391:eDP-1] probed modes: <7> [243.642152] 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> [243.642156] 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> [243.642169] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] <7> [243.642172] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:400:DP-1] <7> [243.642319] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] disconnected <7> [243.642331] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] <7> [243.642334] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:412:DP-2] <7> [243.642586] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] disconnected <7> [243.642597] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] <7> [243.642599] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:420:DP-3] <7> [243.642712] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] disconnected <6> [243.646241] [IGT] kms_flip: starting subtest flip-vs-expired-vblank-interruptible <6> [243.647545] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [243.664031] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:428] <7> [243.664489] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430] <7> [243.714678] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A] <7> [243.714772] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [243.714892] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [243.714979] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [243.715063] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [243.715146] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0) <7> [243.715228] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [243.715308] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [243.715419] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [243.715523] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [243.715626] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [243.715706] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [243.715783] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [243.715859] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [243.715939] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [243.716022] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [243.716104] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [243.716185] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [243.716267] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [243.716351] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [243.716446] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [243.716543] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [243.716639] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [243.716714] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [243.716793] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [243.716866] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [243.716938] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [243.717012] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [243.717083] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [243.717155] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [243.717224] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [243.717294] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [243.717390] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [243.717484] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [243.717575] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [243.717664] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [243.717737] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [243.717807] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [243.717876] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in port_clock (expected 432000, found 0) <7> [243.717947] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] fastset requirement not met, forcing full modeset <7> [243.718018] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:149:pipe A] releasing DPLL 0 <7> [243.718126] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [243.718190] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:149:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [243.718274] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [243.718345] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:143:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [243.718423] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] level wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm <7> [243.718499] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [243.718570] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [243.718644] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [243.718727] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:149:pipe A] data rate 0 num active planes 0 <7> [243.718819] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [243.718910] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [243.718995] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [243.719078] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [243.719166] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [243.719249] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:149:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [243.719363] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [243.719461] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [243.719556] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [243.719647] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [243.719745] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:149:pipe A] enable: no [modeset] <7> [243.719828] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:33:plane 1A] fb: [NOFB], visible: no <7> [243.719912] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:63:plane 2A] fb: [NOFB], visible: no <7> [243.719995] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:93:plane 3A] fb: [NOFB], visible: no <7> [243.720076] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:123:plane 4A] fb: [NOFB], visible: no <7> [243.720150] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:133:plane 5A] fb: [NOFB], visible: no <7> [243.720222] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:143:cursor A] fb: [NOFB], visible: no <7> [243.720579] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [243.720683] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [243.720819] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [243.740993] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [243.741242] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [243.948482] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 0 <7> [243.948851] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [243.951692] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turn panel power off <7> [243.951936] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power off time <7> [243.952182] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [243.952181] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [243.952892] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - short <7> [244.004678] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [244.005056] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - short <7> [244.012379] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [244.012747] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:149:pipe A] <7> [244.012792] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:390:DDI A/PHY A] <7> [244.013270] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:390:DDI A/PHY A] <7> [244.013907] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [244.014233] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [244.014586] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:390:DDI A/PHY A] <7> [244.014820] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:399:DDI TC1/PHY TC1] <7> [244.015033] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DP-MST A] <7> [244.015240] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST B] <7> [244.015465] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST C] <7> [244.015663] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:411:DDI TC2/PHY TC2] <7> [244.015847] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DP-MST A] <7> [244.016029] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST B] <7> [244.016207] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST C] <7> [244.016444] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:419:DDI TC3/PHY TC3] <7> [244.016637] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DP-MST A] <7> [244.016843] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST B] <7> [244.017025] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST C] <7> [244.017204] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:391:eDP-1] <7> [244.017481] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [244.017717] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [244.017898] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [244.018232] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [244.018550] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A] <7> [244.018767] 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> [244.019025] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [244.019237] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [244.019861] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B] <7> [244.020133] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C] <7> [244.020356] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A] <7> [244.020407] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:391:eDP-1] <7> [244.020543] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:391:eDP-1] Limiting display bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [244.020818] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:390:DDI A/PHY A][CRTC:149:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000 <7> [244.021057] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 link rate required 1303913 available 1728000 <7> [244.021346] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [244.021585] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:390:DDI A/PHY A] [CRTC:149:pipe A] <7> [244.021809] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [244.022043] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [244.022260] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [244.022501] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [244.022725] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288) <7> [244.022955] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [244.023204] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [244.023488] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [244.023709] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [244.023925] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880) <7> [244.024143] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040) <7> [244.024366] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928) <7> [244.024594] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960) <7> [244.024811] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [244.025018] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800) <7> [244.025225] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803) <7> [244.025452] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809) <7> [244.025645] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [244.025856] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906) <7> [244.026041] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [244.026221] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [244.026453] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880) <7> [244.026623] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040) <7> [244.026788] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928) <7> [244.026954] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960) <7> [244.027111] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [244.027267] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800) <7> [244.027440] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803) <7> [244.027589] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809) <7> [244.027737] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [244.027881] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906) <7> [244.028020] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [244.028158] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [244.028293] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [244.028447] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [244.028576] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [244.028703] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [244.028832] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in port_clock (expected 0, found 432000) <7> [244.028962] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] fastset requirement not met, forcing full modeset <7> [244.029135] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [244.029257] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:149:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [244.029418] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [244.029519] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:143:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [244.029612] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm <7> [244.029716] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 <7> [244.029823] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 <7> [244.029920] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 <7> [244.030023] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:149:pipe A] data rate 1390840 num active planes 1 <7> [244.030149] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [244.030268] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [244.030404] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [244.030516] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [244.030626] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [244.030737] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:149:pipe A] min cdclk: 0 kHz -> 173855 kHz <7> [244.030864] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [244.030973] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [244.031078] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [244.031179] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [244.031292] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:149:pipe A] allocated DPLL 0 <7> [244.031403] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:149:pipe A] reserving DPLL 0 <7> [244.031504] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:149:pipe A] enable: yes [modeset] <7> [244.031601] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [244.031697] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0 <7> [244.031789] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [244.031880] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [244.031969] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [244.032054] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [244.032139] 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> [244.032224] 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> [244.032304] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [244.032397] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [244.032488] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [244.032578] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0 <7> [244.032661] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [244.032738] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [244.032815] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [244.032889] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [244.032962] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [244.033034] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [244.033106] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [244.033176] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [244.033246] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [244.033315] 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> [244.033471] 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> [244.033565] 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> [244.033654] 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> [244.033727] 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> [244.033797] 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> [244.033867] 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> [244.033936] 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> [244.034004] 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> [244.034072] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [244.034139] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [244.034206] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [244.034278] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [244.034356] 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> [244.034453] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: clock: 432000, fracen: no, <7> [244.034549] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1. <7> [244.034646] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [244.034720] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [244.034784] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1 <7> [244.034850] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [244.034915] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [244.034980] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [244.035045] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23 <7> [244.035110] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [244.035175] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [244.035240] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [244.035305] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.035389] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.035480] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.035574] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [244.035661] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [244.035730] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.035801] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.035867] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.035931] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [244.035999] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [244.036069] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:33:plane 1A] fb: [FB:428] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [244.036141] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [244.036211] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [244.036281] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:63:plane 2A] fb: [NOFB], visible: no <7> [244.036354] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:93:plane 3A] fb: [NOFB], visible: no <7> [244.036445] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:123:plane 4A] fb: [NOFB], visible: no <7> [244.036535] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:133:plane 5A] fb: [NOFB], visible: no <7> [244.036623] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:143:cursor A] fb: [NOFB], visible: no <7> [244.036998] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [244.037140] 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> [244.037223] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [244.037308] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [244.037398] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:390:DDI A/PHY A] <7> [244.037486] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:399:DDI TC1/PHY TC1] <7> [244.037570] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DP-MST A] <7> [244.037651] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST B] <7> [244.037720] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST C] <7> [244.037788] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:411:DDI TC2/PHY TC2] <7> [244.037855] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DP-MST A] <7> [244.037919] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST B] <7> [244.037979] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST C] <7> [244.038041] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:419:DDI TC3/PHY TC3] <7> [244.038102] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DP-MST A] <7> [244.038164] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST B] <7> [244.038224] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST C] <7> [244.038304] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [244.038475] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [244.038554] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [244.038678] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [244.039802] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [244.039928] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - long <7> [244.039998] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:149:pipe A] <7> [244.040018] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [244.040073] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [244.040118] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:390:DDI A/PHY A] <7> [244.041786] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turn panel power on <7> [244.041853] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power cycle (471 ms remaining) <7> [244.516534] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [244.543391] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [244.543685] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power on <7> [244.543954] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [244.580521] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [244.580979] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - long <7> [244.581337] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [244.581767] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:390:DDI A/PHY A] <7> [244.644512] 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> [244.644591] 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> [244.644702] 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> [244.754553] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [244.754920] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turning VDD on <7> [244.755192] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [244.757220] 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> [244.758529] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [244.759285] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05 <7> [244.760419] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [244.761557] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [244.762624] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Clock recovery OK <7> [244.763004] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [244.764491] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [244.764820] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4 <7> [244.765617] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [244.766009] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [244.766289] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [244.766648] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 4518 <7> [244.782876] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [244.784600] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:391:eDP-1] <7> [244.785013] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A] <7> [247.333071] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turning VDD off <7> [247.333640] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067 <7> [252.565299] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [252.565781] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [252.566217] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [252.625867] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

8.98 seconds

Hostname

shard-lnl-8

Igt-Version

IGT-Version: 2.3-g653d1b1eb (x86_64) (Linux: 6.19.0-rc4-lgci-xe-xe-4339-77ca0c5f244b27964+ x86_64)

Out

Using IGT_SRANDOM=1767798583 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:923 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1889 run_test()
  #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045()
  #4 ../tests/kms_flip.c:2045 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (8.977s)

Err

Starting subtest: flip-vs-expired-vblank-interruptible
Starting dynamic subtest: A-eDP1
(kms_flip:5379) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:5379) CRITICAL: Failed assertion: end - start < 500
(kms_flip:5379) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:5379) DEBUG: Vblank took 38us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.438385
last_received_ts = 250.437607
last_seq = 2768
current_ts = 250.455063
current_received_ts = 250.454239
current_seq = 2769
count = 344
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 39us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.455063
last_received_ts = 250.454239
last_seq = 2769
current_ts = 250.471725
current_received_ts = 250.470947
current_seq = 2770
count = 345
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 118us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.471725
last_received_ts = 250.470947
last_seq = 2770
current_ts = 250.488388
current_received_ts = 250.487610
current_seq = 2771
count = 346
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.488388
last_received_ts = 250.487610
last_seq = 2771
current_ts = 250.505051
current_received_ts = 250.504318
current_seq = 2772
count = 347
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 106us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.505051
last_received_ts = 250.504318
last_seq = 2772
current_ts = 250.521713
current_received_ts = 250.520920
current_seq = 2773
count = 348
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 105us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.521713
last_received_ts = 250.520920
last_seq = 2773
current_ts = 250.538376
current_received_ts = 250.537598
current_seq = 2774
count = 349
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 126us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.538376
last_received_ts = 250.537598
last_seq = 2774
current_ts = 250.555038
current_received_ts = 250.554245
current_seq = 2775
count = 350
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 82us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.555038
last_received_ts = 250.554245
last_seq = 2775
current_ts = 250.571701
current_received_ts = 250.570892
current_seq = 2776
count = 351
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 69us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.571701
last_received_ts = 250.570892
last_seq = 2776
current_ts = 250.588364
current_received_ts = 250.587570
current_seq = 2777
count = 352
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 67us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.588364
last_received_ts = 250.587570
last_seq = 2777
current_ts = 250.605042
current_received_ts = 250.604218
current_seq = 2778
count = 353
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 65us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.605042
last_received_ts = 250.604218
last_seq = 2778
current_ts = 250.621689
current_received_ts = 250.620895
current_seq = 2779
count = 354
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 66us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.621689
last_received_ts = 250.620895
last_seq = 2779
current_ts = 250.638351
current_received_ts = 250.637558
current_seq = 2780
count = 355
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 67us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.638351
last_received_ts = 250.637558
last_seq = 2780
current_ts = 250.655029
current_received_ts = 250.654205
current_seq = 2781
count = 356
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 65us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.655029
last_received_ts = 250.654205
last_seq = 2781
current_ts = 250.671692
current_received_ts = 250.670944
current_seq = 2782
count = 357
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 182us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.671692
last_received_ts = 250.670944
last_seq = 2782
current_ts = 250.688354
current_received_ts = 250.687561
current_seq = 2783
count = 358
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 69us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.688354
last_received_ts = 250.687561
last_seq = 2783
current_ts = 250.705017
current_received_ts = 250.704224
current_seq = 2784
count = 359
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 79us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.705017
last_received_ts = 250.704224
last_seq = 2784
current_ts = 250.721680
current_received_ts = 250.720901
current_seq = 2785
count = 360
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 56us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.721680
last_received_ts = 250.720901
last_seq = 2785
current_ts = 250.738342
current_received_ts = 250.737564
current_seq = 2786
count = 361
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 49us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.738342
last_received_ts = 250.737564
last_seq = 2786
current_ts = 250.755005
current_received_ts = 250.754211
current_seq = 2787
count = 362
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 53us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.755005
last_received_ts = 250.754211
last_seq = 2787
current_ts = 250.771667
current_received_ts = 250.770889
current_seq = 2788
count = 363
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 52us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.771667
last_received_ts = 250.770889
last_seq = 2788
current_ts = 250.788345
current_received_ts = 250.787552
current_seq = 2789
count = 364
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 51us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.788345
last_received_ts = 250.787552
last_seq = 2789
current_ts = 250.805008
current_received_ts = 250.804214
current_seq = 2790
count = 365
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 51us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.805008
last_received_ts = 250.804214
last_seq = 2790
current_ts = 250.821671
current_received_ts = 250.820892
current_seq = 2791
count = 366
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 48us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.821671
last_received_ts = 250.820892
last_seq = 2791
current_ts = 250.838333
current_received_ts = 250.837555
current_seq = 2792
count = 367
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 48us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.838333
last_received_ts = 250.837555
last_seq = 2792
current_ts = 250.854996
current_received_ts = 250.854187
current_seq = 2793
count = 368
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 57us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.854996
last_received_ts = 250.854187
last_seq = 2793
current_ts = 250.871658
current_received_ts = 250.870880
current_seq = 2794
count = 369
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 48us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.871658
last_received_ts = 250.870880
last_seq = 2794
current_ts = 250.888321
current_received_ts = 250.887543
current_seq = 2795
count = 370
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 43us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.888321
last_received_ts = 250.887543
last_seq = 2795
current_ts = 250.904984
current_received_ts = 250.904175
current_seq = 2796
count = 371
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 39us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.904984
last_received_ts = 250.904175
last_seq = 2796
current_ts = 250.921646
current_received_ts = 250.920883
current_seq = 2797
count = 372
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 98us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.921646
last_received_ts = 250.920883
last_seq = 2797
current_ts = 250.938309
current_received_ts = 250.937531
current_seq = 2798
count = 373
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 117us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.938309
last_received_ts = 250.937531
last_seq = 2798
current_ts = 250.954987
current_received_ts = 250.954178
current_seq = 2799
count = 374
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 40us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.954987
last_received_ts = 250.954178
last_seq = 2799
current_ts = 250.971649
current_received_ts = 250.970856
current_seq = 2800
count = 375
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 40us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.971649
last_received_ts = 250.970856
last_seq = 2800
current_ts = 250.988312
current_received_ts = 250.987534
current_seq = 2801
count = 376
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 250.988312
last_received_ts = 250.987534
last_seq = 2801
current_ts = 251.004974
current_received_ts = 251.004166
current_seq = 2802
count = 377
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 51us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.004974
last_received_ts = 251.004166
last_seq = 2802
current_ts = 251.021637
current_received_ts = 251.020828
current_seq = 2803
count = 378
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 48us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.021637
last_received_ts = 251.020828
last_seq = 2803
current_ts = 251.038300
current_received_ts = 251.037521
current_seq = 2804
count = 379
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 61us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.038300
last_received_ts = 251.037521
last_seq = 2804
current_ts = 251.054962
current_received_ts = 251.054169
current_seq = 2805
count = 380
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 55us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.054962
last_received_ts = 251.054169
last_seq = 2805
current_ts = 251.071625
current_received_ts = 251.070847
current_seq = 2806
count = 381
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 41us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.071625
last_received_ts = 251.070847
last_seq = 2806
current_ts = 251.088287
current_received_ts = 251.087509
current_seq = 2807
count = 382
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.088287
last_received_ts = 251.087509
last_seq = 2807
current_ts = 251.104950
current_received_ts = 251.104156
current_seq = 2808
count = 383
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 46us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.104950
last_received_ts = 251.104156
last_seq = 2808
current_ts = 251.121628
current_received_ts = 251.120834
current_seq = 2809
count = 384
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 47us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.121628
last_received_ts = 251.120834
last_seq = 2809
current_ts = 251.138290
current_received_ts = 251.137482
current_seq = 2810
count = 385
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 48us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.138290
last_received_ts = 251.137482
last_seq = 2810
current_ts = 251.154953
current_received_ts = 251.154160
current_seq = 2811
count = 386
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.154953
last_received_ts = 251.154160
last_seq = 2811
current_ts = 251.171616
current_received_ts = 251.170837
current_seq = 2812
count = 387
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.171616
last_received_ts = 251.170837
last_seq = 2812
current_ts = 251.188278
current_received_ts = 251.187500
current_seq = 2813
count = 388
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 48us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.188278
last_received_ts = 251.187500
last_seq = 2813
current_ts = 251.204941
current_received_ts = 251.204147
current_seq = 2814
count = 389
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 47us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.204941
last_received_ts = 251.204147
last_seq = 2814
current_ts = 251.221603
current_received_ts = 251.220810
current_seq = 2815
count = 390
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 43us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.221603
last_received_ts = 251.220810
last_seq = 2815
current_ts = 251.238266
current_received_ts = 251.237457
current_seq = 2816
count = 391
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.238266
last_received_ts = 251.237457
last_seq = 2816
current_ts = 251.254929
current_received_ts = 251.254135
current_seq = 2817
count = 392
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.254929
last_received_ts = 251.254135
last_seq = 2817
current_ts = 251.271591
current_received_ts = 251.270813
current_seq = 2818
count = 393
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 45us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.271591
last_received_ts = 251.270813
last_seq = 2818
current_ts = 251.288254
current_received_ts = 251.287476
current_seq = 2819
count = 394
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.288254
last_received_ts = 251.287476
last_seq = 2819
current_ts = 251.304932
current_received_ts = 251.304138
current_seq = 2820
count = 395
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 43us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.304932
last_received_ts = 251.304138
last_seq = 2820
current_ts = 251.321594
current_received_ts = 251.320816
current_seq = 2821
count = 396
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.321594
last_received_ts = 251.320816
last_seq = 2821
current_ts = 251.338257
current_received_ts = 251.337448
current_seq = 2822
count = 397
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 43us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.338257
last_received_ts = 251.337448
last_seq = 2822
current_ts = 251.354919
current_received_ts = 251.354111
current_seq = 2823
count = 398
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 57us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.354919
last_received_ts = 251.354111
last_seq = 2823
current_ts = 251.371582
current_received_ts = 251.370804
current_seq = 2824
count = 399
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 102us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.371582
last_received_ts = 251.370804
last_seq = 2824
current_ts = 251.388245
current_received_ts = 251.387466
current_seq = 2825
count = 400
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 46us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.388245
last_received_ts = 251.387466
last_seq = 2825
current_ts = 251.404907
current_received_ts = 251.404114
current_seq = 2826
count = 401
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 47us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.404907
last_received_ts = 251.404114
last_seq = 2826
current_ts = 251.421570
current_received_ts = 251.420792
current_seq = 2827
count = 402
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 54us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.421570
last_received_ts = 251.420792
last_seq = 2827
current_ts = 251.438232
current_received_ts = 251.437469
current_seq = 2828
count = 403
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 52us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.438232
last_received_ts = 251.437469
last_seq = 2828
current_ts = 251.454910
current_received_ts = 251.454102
current_seq = 2829
count = 404
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 43us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.454910
last_received_ts = 251.454102
last_seq = 2829
current_ts = 251.471573
current_received_ts = 251.470795
current_seq = 2830
count = 405
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 58us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.471573
last_received_ts = 251.470795
last_seq = 2830
current_ts = 251.488235
current_received_ts = 251.487442
current_seq = 2831
count = 406
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 54us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.488235
last_received_ts = 251.487442
last_seq = 2831
current_ts = 251.504898
current_received_ts = 251.504105
current_seq = 2832
count = 407
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.504898
last_received_ts = 251.504105
last_seq = 2832
current_ts = 251.521561
current_received_ts = 251.520782
current_seq = 2833
count = 408
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 48us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.521561
last_received_ts = 251.520782
last_seq = 2833
current_ts = 251.538223
current_received_ts = 251.537445
current_seq = 2834
count = 409
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.538223
last_received_ts = 251.537445
last_seq = 2834
current_ts = 251.554886
current_received_ts = 251.554092
current_seq = 2835
count = 410
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 47us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.554886
last_received_ts = 251.554092
last_seq = 2835
current_ts = 251.571548
current_received_ts = 251.570740
current_seq = 2836
count = 411
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 47us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.571548
last_received_ts = 251.570740
last_seq = 2836
current_ts = 251.588226
current_received_ts = 251.587433
current_seq = 2837
count = 412
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.588226
last_received_ts = 251.587433
last_seq = 2837
current_ts = 251.604874
current_received_ts = 251.604080
current_seq = 2838
count = 413
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 50us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.604874
last_received_ts = 251.604080
last_seq = 2838
current_ts = 251.621552
current_received_ts = 251.620758
current_seq = 2839
count = 414
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 47us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.621552
last_received_ts = 251.620758
last_seq = 2839
current_ts = 251.638214
current_received_ts = 251.637421
current_seq = 2840
count = 415
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 51us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.638214
last_received_ts = 251.637421
last_seq = 2840
current_ts = 251.654877
current_received_ts = 251.654266
current_seq = 2841
count = 416
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 110us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.654877
last_received_ts = 251.654266
last_seq = 2841
current_ts = 251.671539
current_received_ts = 251.670761
current_seq = 2842
count = 417
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 120us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.671539
last_received_ts = 251.670761
last_seq = 2842
current_ts = 251.688202
current_received_ts = 251.687408
current_seq = 2843
count = 418
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 70us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.688202
last_received_ts = 251.687408
last_seq = 2843
current_ts = 251.704865
current_received_ts = 251.704071
current_seq = 2844
count = 419
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 58us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.704865
last_received_ts = 251.704071
last_seq = 2844
current_ts = 251.721527
current_received_ts = 251.720749
current_seq = 2845
count = 420
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 66us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.721527
last_received_ts = 251.720749
last_seq = 2845
current_ts = 251.738205
current_received_ts = 251.737411
current_seq = 2846
count = 421
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 53us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.738205
last_received_ts = 251.737411
last_seq = 2846
current_ts = 251.754852
current_received_ts = 251.754074
current_seq = 2847
count = 422
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 52us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.754852
last_received_ts = 251.754074
last_seq = 2847
current_ts = 251.771515
current_received_ts = 251.770737
current_seq = 2848
count = 423
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.771515
last_received_ts = 251.770737
last_seq = 2848
current_ts = 251.788193
current_received_ts = 251.787399
current_seq = 2849
count = 424
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.788193
last_received_ts = 251.787399
last_seq = 2849
current_ts = 251.804855
current_received_ts = 251.804047
current_seq = 2850
count = 425
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.804855
last_received_ts = 251.804047
last_seq = 2850
current_ts = 251.821518
current_received_ts = 251.820740
current_seq = 2851
count = 426
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 46us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.821518
last_received_ts = 251.820740
last_seq = 2851
current_ts = 251.838181
current_received_ts = 251.837387
current_seq = 2852
count = 427
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 43us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.838181
last_received_ts = 251.837387
last_seq = 2852
current_ts = 251.854843
current_received_ts = 251.854065
current_seq = 2853
count = 428
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 50us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.854843
last_received_ts = 251.854065
last_seq = 2853
current_ts = 251.871506
current_received_ts = 251.870728
current_seq = 2854
count = 429
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 49us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.871506
last_received_ts = 251.870728
last_seq = 2854
current_ts = 251.888168
current_received_ts = 251.887375
current_seq = 2855
count = 430
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.888168
last_received_ts = 251.887375
last_seq = 2855
current_ts = 251.904831
current_received_ts = 251.904068
current_seq = 2856
count = 431
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 56us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.904831
last_received_ts = 251.904068
last_seq = 2856
current_ts = 251.921509
current_received_ts = 251.920685
current_seq = 2857
count = 432
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.921509
last_received_ts = 251.920685
last_seq = 2857
current_ts = 251.938171
current_received_ts = 251.937378
current_seq = 2858
count = 433
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 61us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.938171
last_received_ts = 251.937378
last_seq = 2858
current_ts = 251.954834
current_received_ts = 251.954056
current_seq = 2859
count = 434
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 51us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.954834
last_received_ts = 251.954056
last_seq = 2859
current_ts = 251.971497
current_received_ts = 251.970718
current_seq = 2860
count = 435
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 50us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.971497
last_received_ts = 251.970718
last_seq = 2860
current_ts = 251.988159
current_received_ts = 251.987366
current_seq = 2861
count = 436
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 51us
(kms_flip:5379) DEBUG: name = flip
last_ts = 251.988159
last_received_ts = 251.987366
last_seq = 2861
current_ts = 252.004822
current_received_ts = 252.004059
current_seq = 2862
count = 437
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 48us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.004822
last_received_ts = 252.004059
last_seq = 2862
current_ts = 252.021484
current_received_ts = 252.020706
current_seq = 2863
count = 438
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.021484
last_received_ts = 252.020706
last_seq = 2863
current_ts = 252.038147
current_received_ts = 252.037354
current_seq = 2864
count = 439
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 53us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.038147
last_received_ts = 252.037354
last_seq = 2864
current_ts = 252.054810
current_received_ts = 252.054047
current_seq = 2865
count = 440
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 82us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.054810
last_received_ts = 252.054047
last_seq = 2865
current_ts = 252.071472
current_received_ts = 252.070709
current_seq = 2866
count = 441
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 50us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.071472
last_received_ts = 252.070709
last_seq = 2866
current_ts = 252.088135
current_received_ts = 252.087357
current_seq = 2867
count = 442
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 56us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.088135
last_received_ts = 252.087357
last_seq = 2867
current_ts = 252.104797
current_received_ts = 252.104050
current_seq = 2868
count = 443
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 56us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.104797
last_received_ts = 252.104050
last_seq = 2868
current_ts = 252.121475
current_received_ts = 252.120697
current_seq = 2869
count = 444
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 54us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.121475
last_received_ts = 252.120697
last_seq = 2869
current_ts = 252.138138
current_received_ts = 252.137329
current_seq = 2870
count = 445
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 42us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.138138
last_received_ts = 252.137329
last_seq = 2870
current_ts = 252.154800
current_received_ts = 252.154022
current_seq = 2871
count = 446
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 57us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.154800
last_received_ts = 252.154022
last_seq = 2871
current_ts = 252.171463
current_received_ts = 252.170685
current_seq = 2872
count = 447
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 49us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.171463
last_received_ts = 252.170685
last_seq = 2872
current_ts = 252.188126
current_received_ts = 252.187317
current_seq = 2873
count = 448
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 51us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.188126
last_received_ts = 252.187317
last_seq = 2873
current_ts = 252.204788
current_received_ts = 252.204025
current_seq = 2874
count = 449
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.204788
last_received_ts = 252.204025
last_seq = 2874
current_ts = 252.221451
current_received_ts = 252.220688
current_seq = 2875
count = 450
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 100us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.221451
last_received_ts = 252.220688
last_seq = 2875
current_ts = 252.238129
current_received_ts = 252.237320
current_seq = 2876
count = 451
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 94us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.238129
last_received_ts = 252.237320
last_seq = 2876
current_ts = 252.254791
current_received_ts = 252.253998
current_seq = 2877
count = 452
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 39us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.254791
last_received_ts = 252.253998
last_seq = 2877
current_ts = 252.271454
current_received_ts = 252.270630
current_seq = 2878
count = 453
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 41us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.271454
last_received_ts = 252.270630
last_seq = 2878
current_ts = 252.288116
current_received_ts = 252.287292
current_seq = 2879
count = 454
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 38us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.288116
last_received_ts = 252.287292
last_seq = 2879
current_ts = 252.304779
current_received_ts = 252.304001
current_seq = 2880
count = 455
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 41us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.304779
last_received_ts = 252.304001
last_seq = 2880
current_ts = 252.321442
current_received_ts = 252.320663
current_seq = 2881
count = 456
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 51us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.321442
last_received_ts = 252.320663
last_seq = 2881
current_ts = 252.338104
current_received_ts = 252.337296
current_seq = 2882
count = 457
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 54us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.338104
last_received_ts = 252.337296
last_seq = 2882
current_ts = 252.354767
current_received_ts = 252.353989
current_seq = 2883
count = 458
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 75us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.354767
last_received_ts = 252.353989
last_seq = 2883
current_ts = 252.371429
current_received_ts = 252.370651
current_seq = 2884
count = 459
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.371429
last_received_ts = 252.370651
last_seq = 2884
current_ts = 252.388092
current_received_ts = 252.387283
current_seq = 2885
count = 460
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.388092
last_received_ts = 252.387283
last_seq = 2885
current_ts = 252.404755
current_received_ts = 252.403992
current_seq = 2886
count = 461
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 90us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.404755
last_received_ts = 252.403992
last_seq = 2886
current_ts = 252.421417
current_received_ts = 252.420639
current_seq = 2887
count = 462
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 44us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.421417
last_received_ts = 252.420639
last_seq = 2887
current_ts = 252.438095
current_received_ts = 252.437286
current_seq = 2888
count = 463
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 49us
(kms_flip:5379) DEBUG: name = flip
last_ts = 252.438095
last_received_ts = 252.437286
last_seq = 2888
current_ts = 252.454758
current_received_ts = 252.453979
current_seq = 2889
count = 464
seq_step = 1
(kms_flip:5379) DEBUG: Vblank took 500us
(kms_flip:5379) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:5379) CRITICAL: Failed assertion: end - start < 500
(kms_flip:5379) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:5379) igt_core-INFO: Stack trace:
(kms_flip:5379) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:5379) igt_core-INFO:   #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
(kms_flip:5379) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:5379) igt_core-INFO:   #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045()
(kms_flip:5379) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:5379) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:5379) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:5379) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (8.977s)

Dmesg

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

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

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

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

<7> [243.638928] 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> [243.639021] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] disconnected

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

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

<7> [243.639383] 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> [243.639488] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] disconnected

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

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

<7> [243.639860] 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> [243.639945] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] disconnected

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [243.642152] 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> [243.642156] 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> [243.642169] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1]

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

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

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

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

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

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

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

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

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

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

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

<7> [243.664489] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430]

<7> [243.714678] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [243.718499] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [243.718570] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [243.718644] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [243.718727] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:149:pipe A] data rate 0 num active planes 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.018550] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A]

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

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

<7> [244.019861] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]

<7> [244.020133] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]

<7> [244.020356] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A]

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

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

<7> [244.020818] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:390:DDI A/PHY A][CRTC:149:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000

<7> [244.021057] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 link rate required 1303913 available 1728000

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

<7> [244.021585] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:390:DDI A/PHY A] [CRTC:149:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.029716] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0

<7> [244.029823] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197

<7> [244.029920] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198

<7> [244.030023] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:149:pipe A] data rate 1390840 num active planes 1

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.032139] 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> [244.032224] 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> [244.032304] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.033315] 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> [244.033471] 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> [244.033565] 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> [244.033654] 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> [244.033727] 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> [244.033797] 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> [244.033867] 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> [244.033936] 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> [244.034004] 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> [244.034072] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0

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

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

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

<7> [244.034356] 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> [244.034453] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: clock: 432000, fracen: no,

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.644512] 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> [244.644591] 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> [244.644702] 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> [244.754553] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.785013] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A]

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

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

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

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

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

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

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