igt@kms_flip@flip-vs-expired-vblank@a-edp1 on re-lnl-1@xe-3643-99f4b32d88cb9718c944d44ea96cb04f4f70a773 Test details

Detail	Value
Duration	5.78 seconds
Igt-Version	IGT-Version: 2.1-g8a840cd64 (x86_64) (Linux: 6.17.0-rc3-lgci-xe-xe-3643-99f4b32d88cb9718c+ x86_64)
Out	Using IGT_SRANDOM=1756523542 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 2560x1600: 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 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:1884 run_test() #3 ../tests/kms_flip.c:2117 __igt_unique____real_main2040() #4 ../tests/kms_flip.c:2040 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (5.780s)
Err	Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 (kms_flip:3310) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:3310) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:3310) DEBUG: name = flip last_ts = 779.966919 last_received_ts = 779.966553 last_seq = 29432 current_ts = 779.971069 current_received_ts = 779.970703 current_seq = 29433 count = 903 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 779.971069 last_received_ts = 779.970703 last_seq = 29433 current_ts = 779.975220 current_received_ts = 779.974915 current_seq = 29434 count = 904 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 779.975220 last_received_ts = 779.974915 last_seq = 29434 current_ts = 779.979431 current_received_ts = 779.979065 current_seq = 29435 count = 905 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 779.979431 last_received_ts = 779.979065 last_seq = 29435 current_ts = 779.983582 current_received_ts = 779.983215 current_seq = 29436 count = 906 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 37us (kms_flip:3310) DEBUG: name = flip last_ts = 779.983582 last_received_ts = 779.983215 last_seq = 29436 current_ts = 779.987732 current_received_ts = 779.987366 current_seq = 29437 count = 907 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 779.987732 last_received_ts = 779.987366 last_seq = 29437 current_ts = 779.991943 current_received_ts = 779.991577 current_seq = 29438 count = 908 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 779.991943 last_received_ts = 779.991577 last_seq = 29438 current_ts = 779.996094 current_received_ts = 779.995728 current_seq = 29439 count = 909 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 61us (kms_flip:3310) DEBUG: name = flip last_ts = 779.996094 last_received_ts = 779.995728 last_seq = 29439 current_ts = 780.000244 current_received_ts = 779.999878 current_seq = 29440 count = 910 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.000244 last_received_ts = 779.999878 last_seq = 29440 current_ts = 780.004395 current_received_ts = 780.004089 current_seq = 29441 count = 911 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.004395 last_received_ts = 780.004089 last_seq = 29441 current_ts = 780.008606 current_received_ts = 780.008240 current_seq = 29442 count = 912 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.008606 last_received_ts = 780.008240 last_seq = 29442 current_ts = 780.012756 current_received_ts = 780.012390 current_seq = 29443 count = 913 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.012756 last_received_ts = 780.012390 last_seq = 29443 current_ts = 780.016907 current_received_ts = 780.016541 current_seq = 29444 count = 914 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.016907 last_received_ts = 780.016541 last_seq = 29444 current_ts = 780.021057 current_received_ts = 780.020752 current_seq = 29445 count = 915 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.021057 last_received_ts = 780.020752 last_seq = 29445 current_ts = 780.025269 current_received_ts = 780.024902 current_seq = 29446 count = 916 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.025269 last_received_ts = 780.024902 last_seq = 29446 current_ts = 780.029419 current_received_ts = 780.029053 current_seq = 29447 count = 917 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.029419 last_received_ts = 780.029053 last_seq = 29447 current_ts = 780.033569 current_received_ts = 780.033203 current_seq = 29448 count = 918 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 58us (kms_flip:3310) DEBUG: name = flip last_ts = 780.033569 last_received_ts = 780.033203 last_seq = 29448 current_ts = 780.037781 current_received_ts = 780.037415 current_seq = 29449 count = 919 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 39us (kms_flip:3310) DEBUG: name = flip last_ts = 780.037781 last_received_ts = 780.037415 last_seq = 29449 current_ts = 780.041931 current_received_ts = 780.041565 current_seq = 29450 count = 920 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 58us (kms_flip:3310) DEBUG: name = flip last_ts = 780.041931 last_received_ts = 780.041565 last_seq = 29450 current_ts = 780.046082 current_received_ts = 780.045715 current_seq = 29451 count = 921 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.046082 last_received_ts = 780.045715 last_seq = 29451 current_ts = 780.050232 current_received_ts = 780.049927 current_seq = 29452 count = 922 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.050232 last_received_ts = 780.049927 last_seq = 29452 current_ts = 780.054443 current_received_ts = 780.054077 current_seq = 29453 count = 923 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.054443 last_received_ts = 780.054077 last_seq = 29453 current_ts = 780.058594 current_received_ts = 780.058228 current_seq = 29454 count = 924 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.058594 last_received_ts = 780.058228 last_seq = 29454 current_ts = 780.062744 current_received_ts = 780.062439 current_seq = 29455 count = 925 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.062744 last_received_ts = 780.062439 last_seq = 29455 current_ts = 780.066895 current_received_ts = 780.066589 current_seq = 29456 count = 926 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.066895 last_received_ts = 780.066589 last_seq = 29456 current_ts = 780.071106 current_received_ts = 780.070740 current_seq = 29457 count = 927 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.071106 last_received_ts = 780.070740 last_seq = 29457 current_ts = 780.075256 current_received_ts = 780.074890 current_seq = 29458 count = 928 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 58us (kms_flip:3310) DEBUG: name = flip last_ts = 780.075256 last_received_ts = 780.074890 last_seq = 29458 current_ts = 780.079407 current_received_ts = 780.079041 current_seq = 29459 count = 929 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.079407 last_received_ts = 780.079041 last_seq = 29459 current_ts = 780.083618 current_received_ts = 780.083252 current_seq = 29460 count = 930 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.083618 last_received_ts = 780.083252 last_seq = 29460 current_ts = 780.087769 current_received_ts = 780.087402 current_seq = 29461 count = 931 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.087769 last_received_ts = 780.087402 last_seq = 29461 current_ts = 780.091919 current_received_ts = 780.091614 current_seq = 29462 count = 932 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 39us (kms_flip:3310) DEBUG: name = flip last_ts = 780.091919 last_received_ts = 780.091614 last_seq = 29462 current_ts = 780.096069 current_received_ts = 780.095764 current_seq = 29463 count = 933 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.096069 last_received_ts = 780.095764 last_seq = 29463 current_ts = 780.100281 current_received_ts = 780.099915 current_seq = 29464 count = 934 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.100281 last_received_ts = 780.099915 last_seq = 29464 current_ts = 780.104431 current_received_ts = 780.104065 current_seq = 29465 count = 935 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 61us (kms_flip:3310) DEBUG: name = flip last_ts = 780.104431 last_received_ts = 780.104065 last_seq = 29465 current_ts = 780.108582 current_received_ts = 780.108215 current_seq = 29466 count = 936 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 66us (kms_flip:3310) DEBUG: name = flip last_ts = 780.108582 last_received_ts = 780.108215 last_seq = 29466 current_ts = 780.112732 current_received_ts = 780.112427 current_seq = 29467 count = 937 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 66us (kms_flip:3310) DEBUG: name = flip last_ts = 780.112732 last_received_ts = 780.112427 last_seq = 29467 current_ts = 780.116943 current_received_ts = 780.116577 current_seq = 29468 count = 938 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.116943 last_received_ts = 780.116577 last_seq = 29468 current_ts = 780.121094 current_received_ts = 780.120728 current_seq = 29469 count = 939 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.121094 last_received_ts = 780.120728 last_seq = 29469 current_ts = 780.125244 current_received_ts = 780.124939 current_seq = 29470 count = 940 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.125244 last_received_ts = 780.124939 last_seq = 29470 current_ts = 780.129456 current_received_ts = 780.129089 current_seq = 29471 count = 941 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.129456 last_received_ts = 780.129089 last_seq = 29471 current_ts = 780.133606 current_received_ts = 780.133240 current_seq = 29472 count = 942 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.133606 last_received_ts = 780.133240 last_seq = 29472 current_ts = 780.137756 current_received_ts = 780.137390 current_seq = 29473 count = 943 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.137756 last_received_ts = 780.137390 last_seq = 29473 current_ts = 780.141907 current_received_ts = 780.141602 current_seq = 29474 count = 944 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.141907 last_received_ts = 780.141602 last_seq = 29474 current_ts = 780.146118 current_received_ts = 780.145752 current_seq = 29475 count = 945 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 40us (kms_flip:3310) DEBUG: name = flip last_ts = 780.146118 last_received_ts = 780.145752 last_seq = 29475 current_ts = 780.150269 current_received_ts = 780.149902 current_seq = 29476 count = 946 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 61us (kms_flip:3310) DEBUG: name = flip last_ts = 780.150269 last_received_ts = 780.149902 last_seq = 29476 current_ts = 780.154419 current_received_ts = 780.154053 current_seq = 29477 count = 947 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.154419 last_received_ts = 780.154053 last_seq = 29477 current_ts = 780.158569 current_received_ts = 780.158264 current_seq = 29478 count = 948 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 65us (kms_flip:3310) DEBUG: name = flip last_ts = 780.158569 last_received_ts = 780.158264 last_seq = 29478 current_ts = 780.162781 current_received_ts = 780.162415 current_seq = 29479 count = 949 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.162781 last_received_ts = 780.162415 last_seq = 29479 current_ts = 780.166931 current_received_ts = 780.166565 current_seq = 29480 count = 950 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.166931 last_received_ts = 780.166565 last_seq = 29480 current_ts = 780.171082 current_received_ts = 780.170776 current_seq = 29481 count = 951 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.171082 last_received_ts = 780.170776 last_seq = 29481 current_ts = 780.175293 current_received_ts = 780.174927 current_seq = 29482 count = 952 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.175293 last_received_ts = 780.174927 last_seq = 29482 current_ts = 780.179443 current_received_ts = 780.179077 current_seq = 29483 count = 953 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.179443 last_received_ts = 780.179077 last_seq = 29483 current_ts = 780.183594 current_received_ts = 780.183228 current_seq = 29484 count = 954 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.183594 last_received_ts = 780.183228 last_seq = 29484 current_ts = 780.187744 current_received_ts = 780.187378 current_seq = 29485 count = 955 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.187744 last_received_ts = 780.187378 last_seq = 29485 current_ts = 780.191956 current_received_ts = 780.191589 current_seq = 29486 count = 956 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.191956 last_received_ts = 780.191589 last_seq = 29486 current_ts = 780.196106 current_received_ts = 780.195740 current_seq = 29487 count = 957 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.196106 last_received_ts = 780.195740 last_seq = 29487 current_ts = 780.200256 current_received_ts = 780.199951 current_seq = 29488 count = 958 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.200256 last_received_ts = 780.199951 last_seq = 29488 current_ts = 780.204407 current_received_ts = 780.204102 current_seq = 29489 count = 959 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 40us (kms_flip:3310) DEBUG: name = flip last_ts = 780.204407 last_received_ts = 780.204102 last_seq = 29489 current_ts = 780.208618 current_received_ts = 780.208252 current_seq = 29490 count = 960 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.208618 last_received_ts = 780.208252 last_seq = 29490 current_ts = 780.212769 current_received_ts = 780.212402 current_seq = 29491 count = 961 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.212769 last_received_ts = 780.212402 last_seq = 29491 current_ts = 780.216919 current_received_ts = 780.216614 current_seq = 29492 count = 962 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.216919 last_received_ts = 780.216614 last_seq = 29492 current_ts = 780.221130 current_received_ts = 780.220764 current_seq = 29493 count = 963 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.221130 last_received_ts = 780.220764 last_seq = 29493 current_ts = 780.225281 current_received_ts = 780.224915 current_seq = 29494 count = 964 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.225281 last_received_ts = 780.224915 last_seq = 29494 current_ts = 780.229431 current_received_ts = 780.229065 current_seq = 29495 count = 965 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.229431 last_received_ts = 780.229065 last_seq = 29495 current_ts = 780.233582 current_received_ts = 780.233215 current_seq = 29496 count = 966 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.233582 last_received_ts = 780.233215 last_seq = 29496 current_ts = 780.237793 current_received_ts = 780.237427 current_seq = 29497 count = 967 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.237793 last_received_ts = 780.237427 last_seq = 29497 current_ts = 780.241943 current_received_ts = 780.241577 current_seq = 29498 count = 968 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.241943 last_received_ts = 780.241577 last_seq = 29498 current_ts = 780.246094 current_received_ts = 780.245728 current_seq = 29499 count = 969 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.246094 last_received_ts = 780.245728 last_seq = 29499 current_ts = 780.250244 current_received_ts = 780.249939 current_seq = 29500 count = 970 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.250244 last_received_ts = 780.249939 last_seq = 29500 current_ts = 780.254456 current_received_ts = 780.254089 current_seq = 29501 count = 971 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.254456 last_received_ts = 780.254089 last_seq = 29501 current_ts = 780.258606 current_received_ts = 780.258240 current_seq = 29502 count = 972 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.258606 last_received_ts = 780.258240 last_seq = 29502 current_ts = 780.262756 current_received_ts = 780.262451 current_seq = 29503 count = 973 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 40us (kms_flip:3310) DEBUG: name = flip last_ts = 780.262756 last_received_ts = 780.262451 last_seq = 29503 current_ts = 780.266968 current_received_ts = 780.266602 current_seq = 29504 count = 974 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.266968 last_received_ts = 780.266602 last_seq = 29504 current_ts = 780.271118 current_received_ts = 780.270752 current_seq = 29505 count = 975 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.271118 last_received_ts = 780.270752 last_seq = 29505 current_ts = 780.275269 current_received_ts = 780.274902 current_seq = 29506 count = 976 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.275269 last_received_ts = 780.274902 last_seq = 29506 current_ts = 780.279419 current_received_ts = 780.279114 current_seq = 29507 count = 977 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.279419 last_received_ts = 780.279114 last_seq = 29507 current_ts = 780.283630 current_received_ts = 780.283264 current_seq = 29508 count = 978 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.283630 last_received_ts = 780.283264 last_seq = 29508 current_ts = 780.287781 current_received_ts = 780.287415 current_seq = 29509 count = 979 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.287781 last_received_ts = 780.287415 last_seq = 29509 current_ts = 780.291931 current_received_ts = 780.291565 current_seq = 29510 count = 980 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.291931 last_received_ts = 780.291565 last_seq = 29510 current_ts = 780.296082 current_received_ts = 780.295776 current_seq = 29511 count = 981 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.296082 last_received_ts = 780.295776 last_seq = 29511 current_ts = 780.300293 current_received_ts = 780.299927 current_seq = 29512 count = 982 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 60us (kms_flip:3310) DEBUG: name = flip last_ts = 780.300293 last_received_ts = 780.299927 last_seq = 29512 current_ts = 780.304443 current_received_ts = 780.304077 current_seq = 29513 count = 983 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.304443 last_received_ts = 780.304077 last_seq = 29513 current_ts = 780.308594 current_received_ts = 780.308228 current_seq = 29514 count = 984 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 59us (kms_flip:3310) DEBUG: name = flip last_ts = 780.308594 last_received_ts = 780.308228 last_seq = 29514 current_ts = 780.312805 current_received_ts = 780.312439 current_seq = 29515 count = 985 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.312805 last_received_ts = 780.312439 last_seq = 29515 current_ts = 780.316956 current_received_ts = 780.316589 current_seq = 29516 count = 986 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.316956 last_received_ts = 780.316589 last_seq = 29516 current_ts = 780.321106 current_received_ts = 780.320740 current_seq = 29517 count = 987 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 38us (kms_flip:3310) DEBUG: name = flip last_ts = 780.321106 last_received_ts = 780.320740 last_seq = 29517 current_ts = 780.325256 current_received_ts = 780.324890 current_seq = 29518 count = 988 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 58us (kms_flip:3310) DEBUG: name = flip last_ts = 780.325256 last_received_ts = 780.324890 last_seq = 29518 current_ts = 780.329468 current_received_ts = 780.329102 current_seq = 29519 count = 989 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 38us (kms_flip:3310) DEBUG: name = flip last_ts = 780.329468 last_received_ts = 780.329102 last_seq = 29519 current_ts = 780.333618 current_received_ts = 780.333252 current_seq = 29520 count = 990 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.333618 last_received_ts = 780.333252 last_seq = 29520 current_ts = 780.337769 current_received_ts = 780.337402 current_seq = 29521 count = 991 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.337769 last_received_ts = 780.337402 last_seq = 29521 current_ts = 780.341919 current_received_ts = 780.341614 current_seq = 29522 count = 992 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.341919 last_received_ts = 780.341614 last_seq = 29522 current_ts = 780.346130 current_received_ts = 780.345764 current_seq = 29523 count = 993 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 65us (kms_flip:3310) DEBUG: name = flip last_ts = 780.346130 last_received_ts = 780.345764 last_seq = 29523 current_ts = 780.350281 current_received_ts = 780.349915 current_seq = 29524 count = 994 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 78us (kms_flip:3310) DEBUG: name = flip last_ts = 780.350281 last_received_ts = 780.349915 last_seq = 29524 current_ts = 780.354431 current_received_ts = 780.354126 current_seq = 29525 count = 995 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.354431 last_received_ts = 780.354126 last_seq = 29525 current_ts = 780.358643 current_received_ts = 780.358276 current_seq = 29526 count = 996 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.358643 last_received_ts = 780.358276 last_seq = 29526 current_ts = 780.362793 current_received_ts = 780.362427 current_seq = 29527 count = 997 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 65us (kms_flip:3310) DEBUG: name = flip last_ts = 780.362793 last_received_ts = 780.362427 last_seq = 29527 current_ts = 780.366943 current_received_ts = 780.366577 current_seq = 29528 count = 998 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.366943 last_received_ts = 780.366577 last_seq = 29528 current_ts = 780.371094 current_received_ts = 780.370789 current_seq = 29529 count = 999 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.371094 last_received_ts = 780.370789 last_seq = 29529 current_ts = 780.375305 current_received_ts = 780.374939 current_seq = 29530 count = 1000 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 87us (kms_flip:3310) DEBUG: name = flip last_ts = 780.375305 last_received_ts = 780.374939 last_seq = 29530 current_ts = 780.379456 current_received_ts = 780.379150 current_seq = 29531 count = 1001 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 53us (kms_flip:3310) DEBUG: name = flip last_ts = 780.379456 last_received_ts = 780.379150 last_seq = 29531 current_ts = 780.383606 current_received_ts = 780.383301 current_seq = 29532 count = 1002 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 77us (kms_flip:3310) DEBUG: name = flip last_ts = 780.383606 last_received_ts = 780.383301 last_seq = 29532 current_ts = 780.387756 current_received_ts = 780.387451 current_seq = 29533 count = 1003 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 71us (kms_flip:3310) DEBUG: name = flip last_ts = 780.387756 last_received_ts = 780.387451 last_seq = 29533 current_ts = 780.391968 current_received_ts = 780.391602 current_seq = 29534 count = 1004 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 70us (kms_flip:3310) DEBUG: name = flip last_ts = 780.391968 last_received_ts = 780.391602 last_seq = 29534 current_ts = 780.396118 current_received_ts = 780.395752 current_seq = 29535 count = 1005 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.396118 last_received_ts = 780.395752 last_seq = 29535 current_ts = 780.400269 current_received_ts = 780.399963 current_seq = 29536 count = 1006 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 76us (kms_flip:3310) DEBUG: name = flip last_ts = 780.400269 last_received_ts = 780.399963 last_seq = 29536 current_ts = 780.404480 current_received_ts = 780.404114 current_seq = 29537 count = 1007 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.404480 last_received_ts = 780.404114 last_seq = 29537 current_ts = 780.408630 current_received_ts = 780.408264 current_seq = 29538 count = 1008 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.408630 last_received_ts = 780.408264 last_seq = 29538 current_ts = 780.412781 current_received_ts = 780.412415 current_seq = 29539 count = 1009 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.412781 last_received_ts = 780.412415 last_seq = 29539 current_ts = 780.416931 current_received_ts = 780.416626 current_seq = 29540 count = 1010 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.416931 last_received_ts = 780.416626 last_seq = 29540 current_ts = 780.421143 current_received_ts = 780.420776 current_seq = 29541 count = 1011 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 62us (kms_flip:3310) DEBUG: name = flip last_ts = 780.421143 last_received_ts = 780.420776 last_seq = 29541 current_ts = 780.425293 current_received_ts = 780.424927 current_seq = 29542 count = 1012 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 74us (kms_flip:3310) DEBUG: name = flip last_ts = 780.425293 last_received_ts = 780.424927 last_seq = 29542 current_ts = 780.429443 current_received_ts = 780.429138 current_seq = 29543 count = 1013 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 65us (kms_flip:3310) DEBUG: name = flip last_ts = 780.429443 last_received_ts = 780.429138 last_seq = 29543 current_ts = 780.433594 current_received_ts = 780.433289 current_seq = 29544 count = 1014 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.433594 last_received_ts = 780.433289 last_seq = 29544 current_ts = 780.437805 current_received_ts = 780.437439 current_seq = 29545 count = 1015 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.437805 last_received_ts = 780.437439 last_seq = 29545 current_ts = 780.441956 current_received_ts = 780.441589 current_seq = 29546 count = 1016 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.441956 last_received_ts = 780.441589 last_seq = 29546 current_ts = 780.446106 current_received_ts = 780.445801 current_seq = 29547 count = 1017 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 41us (kms_flip:3310) DEBUG: name = flip last_ts = 780.446106 last_received_ts = 780.445801 last_seq = 29547 current_ts = 780.450317 current_received_ts = 780.449951 current_seq = 29548 count = 1018 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 96us (kms_flip:3310) DEBUG: name = flip last_ts = 780.450317 last_received_ts = 780.449951 last_seq = 29548 current_ts = 780.454468 current_received_ts = 780.454102 current_seq = 29549 count = 1019 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.454468 last_received_ts = 780.454102 last_seq = 29549 current_ts = 780.458618 current_received_ts = 780.458252 current_seq = 29550 count = 1020 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 64us (kms_flip:3310) DEBUG: name = flip last_ts = 780.458618 last_received_ts = 780.458252 last_seq = 29550 current_ts = 780.462769 current_received_ts = 780.462463 current_seq = 29551 count = 1021 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.462769 last_received_ts = 780.462463 last_seq = 29551 current_ts = 780.466980 current_received_ts = 780.466614 current_seq = 29552 count = 1022 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 67us (kms_flip:3310) DEBUG: name = flip last_ts = 780.466980 last_received_ts = 780.466614 last_seq = 29552 current_ts = 780.471130 current_received_ts = 780.470764 current_seq = 29553 count = 1023 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 63us (kms_flip:3310) DEBUG: name = flip last_ts = 780.471130 last_received_ts = 780.470764 last_seq = 29553 current_ts = 780.475281 current_received_ts = 780.474915 current_seq = 29554 count = 1024 seq_step = 1 (kms_flip:3310) DEBUG: Vblank took 548us (kms_flip:3310) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:3310) CRITICAL: Failed assertion: end - start < 500 (kms_flip:3310) igt_core-INFO: Stack trace: (kms_flip:3310) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:3310) igt_core-INFO: #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() (kms_flip:3310) igt_core-INFO: #2 ../tests/kms_flip.c:1884 run_test() (kms_flip:3310) igt_core-INFO: #3 ../tests/kms_flip.c:2117 __igt_unique____real_main2040() (kms_flip:3310) igt_core-INFO: #4 ../tests/kms_flip.c:2040 main() (kms_flip:3310) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:3310) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:3310) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (5.780s)
Dmesg	<6> [793.598703] Console: switching to colour dummy device 80x25 <6> [793.599519] [IGT] kms_flip: executing <7> [793.607381] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:214:DP-1] <7> [793.607401] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:214:DP-1] <7> [793.607634] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (disconnected -> dp-alt) pin assignment: E max lanes: 4 <7> [793.607781] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC1 <7> [793.609093] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PICA_TC <7> [793.613041] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Base DPCD: 12 14 c4 81 01 01 03 80 02 02 06 00 00 00 81 <7> [793.613071] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DPCD: 14 1e c4 81 01 00 03 80 02 02 06 00 00 00 81 <7> [793.613835] xe 0000:00:02.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:214:DP-1][ENCODER:213:DDI TC1/PHY TC1][DPRX] LTTPR common capabilities: 20 1e 80 aa 04 00 01 03 <7> [793.616249] xe 0000:00:02.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:214:DP-1][ENCODER:213:DDI TC1/PHY TC1][LTTPR 1] PHY capabilities: 04 00 00 <7> [793.617703] xe 0000:00:02.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: LTTPR 1: OUI 98-4f-ee dev-ID HBR HW-rev 10.2 SW-rev 2.11 quirks 0x0000 <7> [793.620445] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Base DPCD: 12 14 c4 81 01 01 03 80 02 02 06 00 00 00 81 <7> [793.620457] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DPCD: 14 1e c4 81 01 00 03 80 02 02 06 00 00 00 81 <7> [793.621224] xe 0000:00:02.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DP sink: OUI 00-0c-e7 dev-ID HW-rev 0.0 SW-rev 0.0 quirks 0x0020 <7> [793.623476] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [ENCODER:213:DDI TC1/PHY TC1] MST support: port: yes, sink: MST, modparam: yes -> enable: MST <7> [793.630875] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 01 21 03 7f 3b 07 01 00 00 1f 0e 11 08 00 00 00 <7> [793.631747] xe 0000:00:02.0: [drm:intel_dp_get_dsc_sink_cap [xe]] FEC CAPABILITY: ff <7> [793.632593] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000, 1000000, 2000000 <7> [793.632692] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 270000, 540000, 810000, 1000000 <7> [793.632775] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 270000, 540000, 810000, 1000000 <7> [793.632859] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:214:DP-1] disconnected <7> [793.633302] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:226:DP-2] <7> [793.633309] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:226:DP-2] <7> [793.633434] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PICA_TC <7> [793.633530] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC1 <7> [793.633681] 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> [793.633782] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:226:DP-2] disconnected <7> [793.634106] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:234:DP-3] <7> [793.634111] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:234:DP-3] <7> [793.634235] 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> [793.634323] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:234:DP-3] disconnected <7> [793.634758] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:205:eDP-1] <7> [793.634767] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:205:eDP-1] <7> [793.635304] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 01 21 00 76 0a 02 01 80 00 01 06 66 08 00 00 00 <7> [793.635616] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [793.635699] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000 <7> [793.635781] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000 <7> [793.635914] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:205:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 240 Hz <7> [793.635924] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:205:eDP-1] DisplayID extension version 0x20, primary use 0x02 <7> [793.635926] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:205:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <7> [793.635929] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:205:eDP-1] ELD monitor NE160QDM-NZ7 <7> [793.635932] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:205:eDP-1] ELD size 32, SAD count 0 <7> [793.635960] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:205:eDP-1] VRR capable: yes <7> [793.636069] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:205:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [793.636156] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:205:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <7> [793.636823] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:205:eDP-1] probed modes: <7> [793.636829] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1600": 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 0x48 0xa <7> [793.636833] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1600": 60 293760 2560 2608 2640 2720 1600 1663 1669 1800 0x48 0xa <7> [793.636851] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:214:DP-1] <7> [793.636854] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:214:DP-1] <7> [793.637039] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC1 <7> [793.638057] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PICA_TC <7> [793.641443] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Base DPCD: 12 14 c4 81 01 01 03 80 02 02 06 00 00 00 81 <7> [793.641464] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DPCD: 14 1e c4 81 01 00 03 80 02 02 06 00 00 00 81 <7> [793.642225] xe 0000:00:02.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:214:DP-1][ENCODER:213:DDI TC1/PHY TC1][DPRX] LTTPR common capabilities: 20 1e 80 aa 04 00 01 03 <7> [793.644496] xe 0000:00:02.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:214:DP-1][ENCODER:213:DDI TC1/PHY TC1][LTTPR 1] PHY capabilities: 04 00 00 <7> [793.645349] xe 0000:00:02.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: LTTPR 1: OUI 98-4f-ee dev-ID HBR HW-rev 10.2 SW-rev 2.11 quirks 0x0000 <7> [793.648035] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Base DPCD: 12 14 c4 81 01 01 03 80 02 02 06 00 00 00 81 <7> [793.648047] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DPCD: 14 1e c4 81 01 00 03 80 02 02 06 00 00 00 81 <7> [793.648812] xe 0000:00:02.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DP sink: OUI 00-0c-e7 dev-ID HW-rev 0.0 SW-rev 0.0 quirks 0x0020 <7> [793.651016] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [ENCODER:213:DDI TC1/PHY TC1] MST support: port: yes, sink: MST, modparam: yes -> enable: MST <7> [793.658405] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 01 21 03 7f 3b 07 01 00 00 1f 0e 11 08 00 00 00 <7> [793.659239] xe 0000:00:02.0: [drm:intel_dp_get_dsc_sink_cap [xe]] FEC CAPABILITY: ff <7> [793.660024] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000, 1000000, 2000000 <7> [793.660110] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 270000, 540000, 810000, 1000000 <7> [793.660192] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 270000, 540000, 810000, 1000000 <7> [793.660270] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:214:DP-1] disconnected <7> [793.660292] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:226:DP-2] <7> [793.660296] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:226:DP-2] <7> [793.660408] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:226:DP-2] disconnected <7> [793.660420] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:234:DP-3] <7> [793.660423] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:234:DP-3] <7> [793.660532] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:234:DP-3] disconnected <6> [793.661726] [IGT] kms_flip: starting subtest flip-vs-expired-vblank <6> [793.663638] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [793.664441] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:242] <7> [793.664805] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:244] <7> [793.740093] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PICA_TC <7> [793.740354] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC1 <7> [793.743903] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:88:pipe A] <7> [793.744218] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [793.744479] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [793.744690] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [793.744876] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [793.745075] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 8214124/8388608 link 912680/524288, found tu 0, data 0/0 link 0/0) <7> [793.745255] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [793.745423] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [793.745589] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2560, found 0) <7> [793.745755] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2720, found 0) <7> [793.745921] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2560, found 0) <7> [793.746103] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2720, found 0) <7> [793.746262] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2608, found 0) <7> [793.746418] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2640, found 0) <7> [793.746566] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1600, found 0) <7> [793.746717] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1600, found 0) <7> [793.746868] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1663, found 0) <7> [793.747032] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1669, found 0) <7> [793.747174] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1800, found 0) <7> [793.747316] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1800, found 0) <7> [793.747452] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2560, found 0) <7> [793.747586] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2720, found 0) <7> [793.747719] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2560, found 0) <7> [793.747846] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2720, found 0) <7> [793.747973] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2608, found 0) <7> [793.748120] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2640, found 0) <7> [793.748250] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1600, found 0) <7> [793.748375] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1600, found 0) <7> [793.748499] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1663, found 0) <7> [793.748619] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1669, found 0) <7> [793.748737] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1800, found 0) <7> [793.748856] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1800, found 0) <7> [793.748974] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [793.749163] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [793.749280] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [793.749391] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no) <7> [793.749502] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in pipe_bpp (expected 18, found 0) <7> [793.749609] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 1175040, found 0) <7> [793.749713] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 1175040, found 0) <7> [793.749818] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in port_clock (expected 675000, found 0) <7> [793.749923] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in min_voltage_level (expected 1, found 0) <7> [793.750046] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:88:pipe A] fastset requirement not met, forcing full modeset <7> [793.750229] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [793.750320] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:88:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [793.750450] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 3942) -> ( 0 - 0), size 3942 -> 0 <7> [793.750527] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:83:cursor A] ddb (3942 - 4096) -> ( 0 - 0), size 154 -> 0 <7> [793.750599] 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> [793.750670] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] lines 4, 46, 46, 46, 43, 46, 0, 0, 0, 9, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [793.750736] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] blocks 85, 967, 967, 967, 904, 967, 0, 0, 99, 190, 204 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [793.750801] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] min_ddb 95,1065,1065,1065, 996,1065, 0, 0, 100, 210, 210 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [793.750897] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:88:pipe A] data rate 0 num active planes 0 <7> [793.751024] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [793.751134] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [793.751236] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [793.751335] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [793.751433] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [793.751537] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] Can change cdclk via crawling and squashing <7> [793.751632] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [793.751727] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 0, actual 0 <7> [793.751865] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:88:pipe A] enable: no [modeset] <7> [793.751965] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:33:plane 1A] fb: [NOFB], visible: no <7> [793.752072] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:43:plane 2A] fb: [NOFB], visible: no <7> [793.752170] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:53:plane 3A] fb: [NOFB], visible: no <7> [793.752262] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:63:plane 4A] fb: [NOFB], visible: no <7> [793.752352] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:73:plane 5A] fb: [NOFB], visible: no <7> [793.752443] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:83:cursor A] fb: [NOFB], visible: no <7> [793.752610] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [793.753150] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [793.753323] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling Panel Replay <7> [793.758051] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [793.758289] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [793.758413] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [793.964053] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:205:eDP-1] set backlight PWM = 0 <7> [793.964470] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [793.966367] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 turn panel power off <7> [793.966636] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 wait for panel power off time <7> [793.966902] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [794.027421] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [794.027735] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [794.028129] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:204:DDI A/PHY A] <7> [794.028361] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:213:DDI TC1/PHY TC1] <7> [794.028572] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:215:DP-MST A] <7> [794.028778] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:216:DP-MST B] <7> [794.029019] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:217:DP-MST C] <7> [794.029228] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:225:DDI TC2/PHY TC2] <7> [794.029433] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:227:DP-MST A] <7> [794.029635] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:228:DP-MST B] <7> [794.029838] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:229:DP-MST C] <7> [794.030065] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:233:DDI TC3/PHY TC3] <7> [794.030268] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:235:DP-MST A] <7> [794.030469] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:236:DP-MST B] <7> [794.030671] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:237:DP-MST C] <7> [794.030873] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:205:eDP-1] <7> [794.031136] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 3 (mbus joined: no) <7> [794.031347] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [794.031547] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [794.031913] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [794.032282] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:88:pipe A] <7> [794.032530] 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> [794.032854] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [794.033153] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [794.033534] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:145:pipe B] <7> [794.033821] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:202:pipe C] <7> [794.034114] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:88:pipe A] <7> [794.034186] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:205:eDP-1] <7> [794.034368] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:205:eDP-1] Limiting display bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [794.034691] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:204:DDI A/PHY A][CRTC:88:pipe A] DP link limits: pixel clock 1175040 kHz DSC off max lanes 4 max rate 675000 max pipe_bpp 30 max link_bpp 30.0000 <7> [794.034944] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 675000 bpp input 18 compressed 0.0000 link rate required 2643840 available 2700000 <7> [794.035232] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:88:pipe A] hw max bpp: 30, pipe bpp: 18, dithering: 1 <7> [794.035495] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:204:DDI A/PHY A] [CRTC:88:pipe A] <7> [794.035761] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [794.036040] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [794.036296] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [794.036544] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [794.036792] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [794.037060] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [794.037307] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2560) <7> [794.037552] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2720) <7> [794.037798] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2560) <7> [794.038067] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2720) <7> [794.038313] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2608) <7> [794.038558] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2640) <7> [794.038801] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1600) <7> [794.039067] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1600) <7> [794.039310] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1663) <7> [794.039549] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1669) <7> [794.039794] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1800) <7> [794.040061] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1800) <7> [794.040306] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2560) <7> [794.040548] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2720) <7> [794.040784] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2560) <7> [794.041027] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2720) <7> [794.041252] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2608) <7> [794.041476] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2640) <7> [794.041686] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1600) <7> [794.041895] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1600) <7> [794.042123] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1663) <7> [794.042321] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1669) <7> [794.042517] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1800) <7> [794.042704] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1800) <7> [794.042893] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [794.043111] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [794.043289] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [794.043461] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in enhanced_framing (expected no, found yes) <7> [794.043627] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 18) <7> [794.043792] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in port_clock (expected 0, found 675000) <7> [794.043974] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in min_voltage_level (expected 0, found 1) <7> [794.044143] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:88:pipe A] fastset requirement not met, forcing full modeset <7> [794.044430] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [794.044623] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:88:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [794.044819] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 0) -> ( 0 - 3942), size 0 -> 3942 <7> [794.044936] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:83:cursor A] ddb ( 0 - 0) -> (3942 - 4096), size 0 -> 154 <7> [794.045067] 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> [794.045177] 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, 46, 46, 46, 43, 46, 0, 0, 0, 9, 0 <7> [794.045282] 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 -> 82, 933, 933, 933, 872, 933, 0, 0, 177, 184, 198 <7> [794.045390] 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 -> 163,1054,1054,1054, 973,1054, 0, 0, 178, 325, 325 <7> [794.045530] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:88:pipe A] data rate 4700160 num active planes 1 <7> [794.045725] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 4936 qgv_peak_bw: 38400 <7> [794.045910] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 4936 qgv_peak_bw: 38400 <7> [794.046120] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 4936 qgv_peak_bw: 38400 <7> [794.046319] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 4936 qgv_peak_bw: 38400 <7> [794.046510] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 4936 <7> [794.046693] xe 0000:00:02.0: [drm:intel_plane_calc_min_cdclk [xe]] [PLANE:33:plane 1A] min cdclk (587520 kHz) > [CRTC:88:pipe A] min cdclk (0 kHz) <7> [794.046852] xe 0000:00:02.0: [drm:intel_bw_calc_min_cdclk [xe]] new bandwidth min cdclk (91800 kHz) > old min cdclk (0 kHz) <7> [794.047070] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] Can change cdclk via crawling and squashing <7> [794.047271] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 612000 kHz, actual 612000 kHz <7> [794.047462] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 3, actual 3 <7> [794.047698] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:88:pipe A] enable: yes [modeset] <7> [794.047910] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [794.048139] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 18, dithering: 1 <7> [794.048361] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [794.048574] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [794.048789] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [794.049014] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [794.049242] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 8214124, data_n: 8388608, link_m: 912680, link_n: 524288, tu: 64 <7> [794.049474] 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> [794.049705] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled <7> [794.049950] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [794.050219] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: disabled, selective update: enabled, panel replay: enabled, selective fetch: enabled <7> [794.050470] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0 <7> [794.050716] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [794.050978] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 6, length 16 <7> [794.051230] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [794.051477] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [794.051722] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [794.051988] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [794.051995] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [794.052242] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [794.052278] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [794.052486] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [794.052528] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <7> [794.052731] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vblank delay: 0, framestart delay: 1, MSA timing delay: 0 <7> [794.052985] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1800, vmax: 1800, flipline: 1800, pipeline full: 0, guardband: 200 vsync start: 137, vsync end: 131 <7> [794.053236] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1600, vmax vblank: 1600, vmin vtotal: 1800, vmax vtotal: 1800 <7> [794.053481] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2560x1600": 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 0x48 0xa <7> [794.053729] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2560x1600": 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 0x48 0xa <7> [794.053992] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=1175040, hd=2560 hb=2560-2720 hs=2608-2640 ht=2720, vd=1600 vb=1600-1800 vs=1663-1669 vt=1800, flags=0xa <7> [794.054247] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2560x1600": 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 0x40 0xa <7> [794.054496] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=1175040, hd=2560 hb=2560-2720 hs=2608-2640 ht=2720, vd=1600 vb=1600-1800 vs=1663-1669 vt=1800, flags=0xa <7> [794.054743] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 675000, pipe src: 2560x1600+0+0, pixel rate 1175040 <7> [794.055018] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 19, ips linetime: 0 <7> [794.055265] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [794.055509] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [794.055753] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [794.056019] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dpll_hw_state: dpll: 0xa4cb8, dpll_md: 0xb42110, fp0: 0x13e, fp1: 0x1000000 <7> [794.056268] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [794.056510] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [794.056740] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [794.056980] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [794.057209] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [794.057427] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [794.057640] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [794.057849] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [794.058064] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [794.058269] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [794.058463] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [794.058652] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [794.058843] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:33:plane 1A] fb: [FB:242] 2560x1600 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [794.059051] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [794.059233] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2560.000000x1600.000000+0.000000+0.000000 dst: 2560x1600+0+0 <7> [794.059408] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:43:plane 2A] fb: [NOFB], visible: no <7> [794.059577] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:53:plane 3A] fb: [NOFB], visible: no <7> [794.059749] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:63:plane 4A] fb: [NOFB], visible: no <7> [794.059912] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:73:plane 5A] fb: [NOFB], visible: no <7> [794.060089] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:83:cursor A] fb: [NOFB], visible: no <7> [794.060746] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [794.061086] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [794.061310] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [794.061521] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 612000 kHz, VCO 1305600 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 3 <7> [794.061717] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 3 (mbus joined: no) <7> [794.061846] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=1530 <7> [794.061994] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:204:DDI A/PHY A] <7> [794.062104] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:213:DDI TC1/PHY TC1] <7> [794.062200] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:215:DP-MST A] <7> [794.062293] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:216:DP-MST B] <7> [794.062386] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:217:DP-MST C] <7> [794.062475] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:225:DDI TC2/PHY TC2] <7> [794.062565] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:227:DP-MST A] <7> [794.062652] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:228:DP-MST B] <7> [794.062737] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:229:DP-MST C] <7> [794.062820] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:233:DDI TC3/PHY TC3] <7> [794.062904] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:235:DP-MST A] <7> [794.062997] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:236:DP-MST B] <7> [794.063083] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:237:DP-MST C] <7> [794.063167] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [794.063350] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [794.063431] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 6 (mbus joined: yes) <7> [794.063559] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [794.064894] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 turning VDD on <7> [794.065032] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 wait for panel power cycle (463 ms remaining) <7> [794.532118] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [794.541951] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [794.542220] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 PP_STATUS: 0x00000000 PP_CONTROL: 0x00000068 <7> [794.542445] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 panel power wasn't enabled <7> [794.724008] 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> [794.723997] 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> [794.724049] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (dp-alt -> disconnected) pin assignment: E max lanes: 4 <7> [794.748390] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 turn panel power on <7> [794.748678] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 wait for panel power cycle (0 ms remaining) <7> [794.749028] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x00000000 PP_CONTROL: 0x00000068 <7> [794.758948] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [794.759270] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 wait for panel power on <7> [794.759568] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x0000006b <7> [794.972141] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [794.976361] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e c4 c1 00 00 01 c0 02 00 02 00 08 09 84 <7> [794.978029] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [794.978852] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 07 <7> [794.979999] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [794.981091] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [794.982066] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Clock recovery OK <7> [794.982339] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [795.000335] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [795.000682] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Link Training passed at link rate = 675000, lane count = 4 <7> [795.001498] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [795.002023] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [795.002374] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [795.002797] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:205:eDP-1] set backlight PWM = 13892 <7> [795.003333] xe 0000:00:02.0: [drm:i915_hotplug_work_func [xe]] running encoder hotplug functions <7> [795.006273] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling Panel Replay <7> [795.008116] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:205:eDP-1] <7> [795.008509] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:88:pipe A] <3> [795.437495] usb usb4-port1: Cannot enable. Maybe the USB cable is bad? <4> [795.437606] usb usb4-port1: config error <7> [797.539978] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 turning VDD off <7> [797.540501] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067 <7> [799.302614] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [799.303221] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [799.303942] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [799.445010] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

5.78 seconds

Igt-Version

IGT-Version: 2.1-g8a840cd64 (x86_64) (Linux: 6.17.0-rc3-lgci-xe-xe-3643-99f4b32d88cb9718c+ x86_64)

Out

Using IGT_SRANDOM=1756523542 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
  2560x1600: 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 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:1884 run_test()
  #3 ../tests/kms_flip.c:2117 __igt_unique____real_main2040()
  #4 ../tests/kms_flip.c:2040 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (5.780s)

Err

Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
(kms_flip:3310) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:3310) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:3310) DEBUG: name = flip
last_ts = 779.966919
last_received_ts = 779.966553
last_seq = 29432
current_ts = 779.971069
current_received_ts = 779.970703
current_seq = 29433
count = 903
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 779.971069
last_received_ts = 779.970703
last_seq = 29433
current_ts = 779.975220
current_received_ts = 779.974915
current_seq = 29434
count = 904
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 779.975220
last_received_ts = 779.974915
last_seq = 29434
current_ts = 779.979431
current_received_ts = 779.979065
current_seq = 29435
count = 905
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 779.979431
last_received_ts = 779.979065
last_seq = 29435
current_ts = 779.983582
current_received_ts = 779.983215
current_seq = 29436
count = 906
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 37us
(kms_flip:3310) DEBUG: name = flip
last_ts = 779.983582
last_received_ts = 779.983215
last_seq = 29436
current_ts = 779.987732
current_received_ts = 779.987366
current_seq = 29437
count = 907
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 779.987732
last_received_ts = 779.987366
last_seq = 29437
current_ts = 779.991943
current_received_ts = 779.991577
current_seq = 29438
count = 908
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 779.991943
last_received_ts = 779.991577
last_seq = 29438
current_ts = 779.996094
current_received_ts = 779.995728
current_seq = 29439
count = 909
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 61us
(kms_flip:3310) DEBUG: name = flip
last_ts = 779.996094
last_received_ts = 779.995728
last_seq = 29439
current_ts = 780.000244
current_received_ts = 779.999878
current_seq = 29440
count = 910
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.000244
last_received_ts = 779.999878
last_seq = 29440
current_ts = 780.004395
current_received_ts = 780.004089
current_seq = 29441
count = 911
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.004395
last_received_ts = 780.004089
last_seq = 29441
current_ts = 780.008606
current_received_ts = 780.008240
current_seq = 29442
count = 912
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.008606
last_received_ts = 780.008240
last_seq = 29442
current_ts = 780.012756
current_received_ts = 780.012390
current_seq = 29443
count = 913
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.012756
last_received_ts = 780.012390
last_seq = 29443
current_ts = 780.016907
current_received_ts = 780.016541
current_seq = 29444
count = 914
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.016907
last_received_ts = 780.016541
last_seq = 29444
current_ts = 780.021057
current_received_ts = 780.020752
current_seq = 29445
count = 915
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.021057
last_received_ts = 780.020752
last_seq = 29445
current_ts = 780.025269
current_received_ts = 780.024902
current_seq = 29446
count = 916
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.025269
last_received_ts = 780.024902
last_seq = 29446
current_ts = 780.029419
current_received_ts = 780.029053
current_seq = 29447
count = 917
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.029419
last_received_ts = 780.029053
last_seq = 29447
current_ts = 780.033569
current_received_ts = 780.033203
current_seq = 29448
count = 918
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 58us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.033569
last_received_ts = 780.033203
last_seq = 29448
current_ts = 780.037781
current_received_ts = 780.037415
current_seq = 29449
count = 919
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 39us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.037781
last_received_ts = 780.037415
last_seq = 29449
current_ts = 780.041931
current_received_ts = 780.041565
current_seq = 29450
count = 920
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 58us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.041931
last_received_ts = 780.041565
last_seq = 29450
current_ts = 780.046082
current_received_ts = 780.045715
current_seq = 29451
count = 921
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.046082
last_received_ts = 780.045715
last_seq = 29451
current_ts = 780.050232
current_received_ts = 780.049927
current_seq = 29452
count = 922
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.050232
last_received_ts = 780.049927
last_seq = 29452
current_ts = 780.054443
current_received_ts = 780.054077
current_seq = 29453
count = 923
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.054443
last_received_ts = 780.054077
last_seq = 29453
current_ts = 780.058594
current_received_ts = 780.058228
current_seq = 29454
count = 924
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.058594
last_received_ts = 780.058228
last_seq = 29454
current_ts = 780.062744
current_received_ts = 780.062439
current_seq = 29455
count = 925
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.062744
last_received_ts = 780.062439
last_seq = 29455
current_ts = 780.066895
current_received_ts = 780.066589
current_seq = 29456
count = 926
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.066895
last_received_ts = 780.066589
last_seq = 29456
current_ts = 780.071106
current_received_ts = 780.070740
current_seq = 29457
count = 927
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.071106
last_received_ts = 780.070740
last_seq = 29457
current_ts = 780.075256
current_received_ts = 780.074890
current_seq = 29458
count = 928
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 58us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.075256
last_received_ts = 780.074890
last_seq = 29458
current_ts = 780.079407
current_received_ts = 780.079041
current_seq = 29459
count = 929
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.079407
last_received_ts = 780.079041
last_seq = 29459
current_ts = 780.083618
current_received_ts = 780.083252
current_seq = 29460
count = 930
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.083618
last_received_ts = 780.083252
last_seq = 29460
current_ts = 780.087769
current_received_ts = 780.087402
current_seq = 29461
count = 931
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.087769
last_received_ts = 780.087402
last_seq = 29461
current_ts = 780.091919
current_received_ts = 780.091614
current_seq = 29462
count = 932
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 39us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.091919
last_received_ts = 780.091614
last_seq = 29462
current_ts = 780.096069
current_received_ts = 780.095764
current_seq = 29463
count = 933
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.096069
last_received_ts = 780.095764
last_seq = 29463
current_ts = 780.100281
current_received_ts = 780.099915
current_seq = 29464
count = 934
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.100281
last_received_ts = 780.099915
last_seq = 29464
current_ts = 780.104431
current_received_ts = 780.104065
current_seq = 29465
count = 935
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 61us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.104431
last_received_ts = 780.104065
last_seq = 29465
current_ts = 780.108582
current_received_ts = 780.108215
current_seq = 29466
count = 936
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 66us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.108582
last_received_ts = 780.108215
last_seq = 29466
current_ts = 780.112732
current_received_ts = 780.112427
current_seq = 29467
count = 937
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 66us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.112732
last_received_ts = 780.112427
last_seq = 29467
current_ts = 780.116943
current_received_ts = 780.116577
current_seq = 29468
count = 938
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.116943
last_received_ts = 780.116577
last_seq = 29468
current_ts = 780.121094
current_received_ts = 780.120728
current_seq = 29469
count = 939
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.121094
last_received_ts = 780.120728
last_seq = 29469
current_ts = 780.125244
current_received_ts = 780.124939
current_seq = 29470
count = 940
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.125244
last_received_ts = 780.124939
last_seq = 29470
current_ts = 780.129456
current_received_ts = 780.129089
current_seq = 29471
count = 941
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.129456
last_received_ts = 780.129089
last_seq = 29471
current_ts = 780.133606
current_received_ts = 780.133240
current_seq = 29472
count = 942
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.133606
last_received_ts = 780.133240
last_seq = 29472
current_ts = 780.137756
current_received_ts = 780.137390
current_seq = 29473
count = 943
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.137756
last_received_ts = 780.137390
last_seq = 29473
current_ts = 780.141907
current_received_ts = 780.141602
current_seq = 29474
count = 944
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.141907
last_received_ts = 780.141602
last_seq = 29474
current_ts = 780.146118
current_received_ts = 780.145752
current_seq = 29475
count = 945
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 40us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.146118
last_received_ts = 780.145752
last_seq = 29475
current_ts = 780.150269
current_received_ts = 780.149902
current_seq = 29476
count = 946
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 61us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.150269
last_received_ts = 780.149902
last_seq = 29476
current_ts = 780.154419
current_received_ts = 780.154053
current_seq = 29477
count = 947
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.154419
last_received_ts = 780.154053
last_seq = 29477
current_ts = 780.158569
current_received_ts = 780.158264
current_seq = 29478
count = 948
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 65us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.158569
last_received_ts = 780.158264
last_seq = 29478
current_ts = 780.162781
current_received_ts = 780.162415
current_seq = 29479
count = 949
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.162781
last_received_ts = 780.162415
last_seq = 29479
current_ts = 780.166931
current_received_ts = 780.166565
current_seq = 29480
count = 950
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.166931
last_received_ts = 780.166565
last_seq = 29480
current_ts = 780.171082
current_received_ts = 780.170776
current_seq = 29481
count = 951
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.171082
last_received_ts = 780.170776
last_seq = 29481
current_ts = 780.175293
current_received_ts = 780.174927
current_seq = 29482
count = 952
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.175293
last_received_ts = 780.174927
last_seq = 29482
current_ts = 780.179443
current_received_ts = 780.179077
current_seq = 29483
count = 953
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.179443
last_received_ts = 780.179077
last_seq = 29483
current_ts = 780.183594
current_received_ts = 780.183228
current_seq = 29484
count = 954
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.183594
last_received_ts = 780.183228
last_seq = 29484
current_ts = 780.187744
current_received_ts = 780.187378
current_seq = 29485
count = 955
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.187744
last_received_ts = 780.187378
last_seq = 29485
current_ts = 780.191956
current_received_ts = 780.191589
current_seq = 29486
count = 956
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.191956
last_received_ts = 780.191589
last_seq = 29486
current_ts = 780.196106
current_received_ts = 780.195740
current_seq = 29487
count = 957
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.196106
last_received_ts = 780.195740
last_seq = 29487
current_ts = 780.200256
current_received_ts = 780.199951
current_seq = 29488
count = 958
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.200256
last_received_ts = 780.199951
last_seq = 29488
current_ts = 780.204407
current_received_ts = 780.204102
current_seq = 29489
count = 959
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 40us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.204407
last_received_ts = 780.204102
last_seq = 29489
current_ts = 780.208618
current_received_ts = 780.208252
current_seq = 29490
count = 960
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.208618
last_received_ts = 780.208252
last_seq = 29490
current_ts = 780.212769
current_received_ts = 780.212402
current_seq = 29491
count = 961
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.212769
last_received_ts = 780.212402
last_seq = 29491
current_ts = 780.216919
current_received_ts = 780.216614
current_seq = 29492
count = 962
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.216919
last_received_ts = 780.216614
last_seq = 29492
current_ts = 780.221130
current_received_ts = 780.220764
current_seq = 29493
count = 963
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.221130
last_received_ts = 780.220764
last_seq = 29493
current_ts = 780.225281
current_received_ts = 780.224915
current_seq = 29494
count = 964
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.225281
last_received_ts = 780.224915
last_seq = 29494
current_ts = 780.229431
current_received_ts = 780.229065
current_seq = 29495
count = 965
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.229431
last_received_ts = 780.229065
last_seq = 29495
current_ts = 780.233582
current_received_ts = 780.233215
current_seq = 29496
count = 966
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.233582
last_received_ts = 780.233215
last_seq = 29496
current_ts = 780.237793
current_received_ts = 780.237427
current_seq = 29497
count = 967
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.237793
last_received_ts = 780.237427
last_seq = 29497
current_ts = 780.241943
current_received_ts = 780.241577
current_seq = 29498
count = 968
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.241943
last_received_ts = 780.241577
last_seq = 29498
current_ts = 780.246094
current_received_ts = 780.245728
current_seq = 29499
count = 969
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.246094
last_received_ts = 780.245728
last_seq = 29499
current_ts = 780.250244
current_received_ts = 780.249939
current_seq = 29500
count = 970
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.250244
last_received_ts = 780.249939
last_seq = 29500
current_ts = 780.254456
current_received_ts = 780.254089
current_seq = 29501
count = 971
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.254456
last_received_ts = 780.254089
last_seq = 29501
current_ts = 780.258606
current_received_ts = 780.258240
current_seq = 29502
count = 972
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.258606
last_received_ts = 780.258240
last_seq = 29502
current_ts = 780.262756
current_received_ts = 780.262451
current_seq = 29503
count = 973
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 40us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.262756
last_received_ts = 780.262451
last_seq = 29503
current_ts = 780.266968
current_received_ts = 780.266602
current_seq = 29504
count = 974
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.266968
last_received_ts = 780.266602
last_seq = 29504
current_ts = 780.271118
current_received_ts = 780.270752
current_seq = 29505
count = 975
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.271118
last_received_ts = 780.270752
last_seq = 29505
current_ts = 780.275269
current_received_ts = 780.274902
current_seq = 29506
count = 976
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.275269
last_received_ts = 780.274902
last_seq = 29506
current_ts = 780.279419
current_received_ts = 780.279114
current_seq = 29507
count = 977
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.279419
last_received_ts = 780.279114
last_seq = 29507
current_ts = 780.283630
current_received_ts = 780.283264
current_seq = 29508
count = 978
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.283630
last_received_ts = 780.283264
last_seq = 29508
current_ts = 780.287781
current_received_ts = 780.287415
current_seq = 29509
count = 979
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.287781
last_received_ts = 780.287415
last_seq = 29509
current_ts = 780.291931
current_received_ts = 780.291565
current_seq = 29510
count = 980
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.291931
last_received_ts = 780.291565
last_seq = 29510
current_ts = 780.296082
current_received_ts = 780.295776
current_seq = 29511
count = 981
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.296082
last_received_ts = 780.295776
last_seq = 29511
current_ts = 780.300293
current_received_ts = 780.299927
current_seq = 29512
count = 982
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 60us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.300293
last_received_ts = 780.299927
last_seq = 29512
current_ts = 780.304443
current_received_ts = 780.304077
current_seq = 29513
count = 983
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.304443
last_received_ts = 780.304077
last_seq = 29513
current_ts = 780.308594
current_received_ts = 780.308228
current_seq = 29514
count = 984
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 59us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.308594
last_received_ts = 780.308228
last_seq = 29514
current_ts = 780.312805
current_received_ts = 780.312439
current_seq = 29515
count = 985
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.312805
last_received_ts = 780.312439
last_seq = 29515
current_ts = 780.316956
current_received_ts = 780.316589
current_seq = 29516
count = 986
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.316956
last_received_ts = 780.316589
last_seq = 29516
current_ts = 780.321106
current_received_ts = 780.320740
current_seq = 29517
count = 987
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 38us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.321106
last_received_ts = 780.320740
last_seq = 29517
current_ts = 780.325256
current_received_ts = 780.324890
current_seq = 29518
count = 988
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 58us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.325256
last_received_ts = 780.324890
last_seq = 29518
current_ts = 780.329468
current_received_ts = 780.329102
current_seq = 29519
count = 989
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 38us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.329468
last_received_ts = 780.329102
last_seq = 29519
current_ts = 780.333618
current_received_ts = 780.333252
current_seq = 29520
count = 990
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.333618
last_received_ts = 780.333252
last_seq = 29520
current_ts = 780.337769
current_received_ts = 780.337402
current_seq = 29521
count = 991
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.337769
last_received_ts = 780.337402
last_seq = 29521
current_ts = 780.341919
current_received_ts = 780.341614
current_seq = 29522
count = 992
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.341919
last_received_ts = 780.341614
last_seq = 29522
current_ts = 780.346130
current_received_ts = 780.345764
current_seq = 29523
count = 993
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 65us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.346130
last_received_ts = 780.345764
last_seq = 29523
current_ts = 780.350281
current_received_ts = 780.349915
current_seq = 29524
count = 994
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 78us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.350281
last_received_ts = 780.349915
last_seq = 29524
current_ts = 780.354431
current_received_ts = 780.354126
current_seq = 29525
count = 995
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.354431
last_received_ts = 780.354126
last_seq = 29525
current_ts = 780.358643
current_received_ts = 780.358276
current_seq = 29526
count = 996
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.358643
last_received_ts = 780.358276
last_seq = 29526
current_ts = 780.362793
current_received_ts = 780.362427
current_seq = 29527
count = 997
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 65us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.362793
last_received_ts = 780.362427
last_seq = 29527
current_ts = 780.366943
current_received_ts = 780.366577
current_seq = 29528
count = 998
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.366943
last_received_ts = 780.366577
last_seq = 29528
current_ts = 780.371094
current_received_ts = 780.370789
current_seq = 29529
count = 999
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.371094
last_received_ts = 780.370789
last_seq = 29529
current_ts = 780.375305
current_received_ts = 780.374939
current_seq = 29530
count = 1000
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 87us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.375305
last_received_ts = 780.374939
last_seq = 29530
current_ts = 780.379456
current_received_ts = 780.379150
current_seq = 29531
count = 1001
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 53us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.379456
last_received_ts = 780.379150
last_seq = 29531
current_ts = 780.383606
current_received_ts = 780.383301
current_seq = 29532
count = 1002
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 77us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.383606
last_received_ts = 780.383301
last_seq = 29532
current_ts = 780.387756
current_received_ts = 780.387451
current_seq = 29533
count = 1003
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 71us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.387756
last_received_ts = 780.387451
last_seq = 29533
current_ts = 780.391968
current_received_ts = 780.391602
current_seq = 29534
count = 1004
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 70us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.391968
last_received_ts = 780.391602
last_seq = 29534
current_ts = 780.396118
current_received_ts = 780.395752
current_seq = 29535
count = 1005
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.396118
last_received_ts = 780.395752
last_seq = 29535
current_ts = 780.400269
current_received_ts = 780.399963
current_seq = 29536
count = 1006
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 76us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.400269
last_received_ts = 780.399963
last_seq = 29536
current_ts = 780.404480
current_received_ts = 780.404114
current_seq = 29537
count = 1007
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.404480
last_received_ts = 780.404114
last_seq = 29537
current_ts = 780.408630
current_received_ts = 780.408264
current_seq = 29538
count = 1008
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.408630
last_received_ts = 780.408264
last_seq = 29538
current_ts = 780.412781
current_received_ts = 780.412415
current_seq = 29539
count = 1009
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.412781
last_received_ts = 780.412415
last_seq = 29539
current_ts = 780.416931
current_received_ts = 780.416626
current_seq = 29540
count = 1010
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.416931
last_received_ts = 780.416626
last_seq = 29540
current_ts = 780.421143
current_received_ts = 780.420776
current_seq = 29541
count = 1011
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 62us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.421143
last_received_ts = 780.420776
last_seq = 29541
current_ts = 780.425293
current_received_ts = 780.424927
current_seq = 29542
count = 1012
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 74us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.425293
last_received_ts = 780.424927
last_seq = 29542
current_ts = 780.429443
current_received_ts = 780.429138
current_seq = 29543
count = 1013
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 65us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.429443
last_received_ts = 780.429138
last_seq = 29543
current_ts = 780.433594
current_received_ts = 780.433289
current_seq = 29544
count = 1014
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.433594
last_received_ts = 780.433289
last_seq = 29544
current_ts = 780.437805
current_received_ts = 780.437439
current_seq = 29545
count = 1015
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.437805
last_received_ts = 780.437439
last_seq = 29545
current_ts = 780.441956
current_received_ts = 780.441589
current_seq = 29546
count = 1016
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.441956
last_received_ts = 780.441589
last_seq = 29546
current_ts = 780.446106
current_received_ts = 780.445801
current_seq = 29547
count = 1017
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 41us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.446106
last_received_ts = 780.445801
last_seq = 29547
current_ts = 780.450317
current_received_ts = 780.449951
current_seq = 29548
count = 1018
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 96us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.450317
last_received_ts = 780.449951
last_seq = 29548
current_ts = 780.454468
current_received_ts = 780.454102
current_seq = 29549
count = 1019
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.454468
last_received_ts = 780.454102
last_seq = 29549
current_ts = 780.458618
current_received_ts = 780.458252
current_seq = 29550
count = 1020
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 64us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.458618
last_received_ts = 780.458252
last_seq = 29550
current_ts = 780.462769
current_received_ts = 780.462463
current_seq = 29551
count = 1021
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.462769
last_received_ts = 780.462463
last_seq = 29551
current_ts = 780.466980
current_received_ts = 780.466614
current_seq = 29552
count = 1022
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 67us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.466980
last_received_ts = 780.466614
last_seq = 29552
current_ts = 780.471130
current_received_ts = 780.470764
current_seq = 29553
count = 1023
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 63us
(kms_flip:3310) DEBUG: name = flip
last_ts = 780.471130
last_received_ts = 780.470764
last_seq = 29553
current_ts = 780.475281
current_received_ts = 780.474915
current_seq = 29554
count = 1024
seq_step = 1
(kms_flip:3310) DEBUG: Vblank took 548us
(kms_flip:3310) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:3310) CRITICAL: Failed assertion: end - start < 500
(kms_flip:3310) igt_core-INFO: Stack trace:
(kms_flip:3310) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:3310) igt_core-INFO:   #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
(kms_flip:3310) igt_core-INFO:   #2 ../tests/kms_flip.c:1884 run_test()
(kms_flip:3310) igt_core-INFO:   #3 ../tests/kms_flip.c:2117 __igt_unique____real_main2040()
(kms_flip:3310) igt_core-INFO:   #4 ../tests/kms_flip.c:2040 main()
(kms_flip:3310) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:3310) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:3310) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (5.780s)

Dmesg

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

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

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

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

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

<7> [793.607781] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC1

<7> [793.609093] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PICA_TC

<7> [793.613041] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Base DPCD: 12 14 c4 81 01 01 03 80 02 02 06 00 00 00 81

<7> [793.613071] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DPCD: 14 1e c4 81 01 00 03 80 02 02 06 00 00 00 81

<7> [793.613835] xe 0000:00:02.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:214:DP-1][ENCODER:213:DDI TC1/PHY TC1][DPRX] LTTPR common capabilities: 20 1e 80 aa 04 00 01 03

<7> [793.616249] xe 0000:00:02.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:214:DP-1][ENCODER:213:DDI TC1/PHY TC1][LTTPR 1] PHY capabilities: 04 00 00

<7> [793.617703] xe 0000:00:02.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: LTTPR 1: OUI 98-4f-ee dev-ID HBR HW-rev 10.2 SW-rev 2.11 quirks 0x0000

<7> [793.620445] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Base DPCD: 12 14 c4 81 01 01 03 80 02 02 06 00 00 00 81

<7> [793.620457] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DPCD: 14 1e c4 81 01 00 03 80 02 02 06 00 00 00 81

<7> [793.621224] xe 0000:00:02.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DP sink: OUI 00-0c-e7 dev-ID HW-rev 0.0 SW-rev 0.0 quirks 0x0020

<7> [793.623476] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [ENCODER:213:DDI TC1/PHY TC1] MST support: port: yes, sink: MST, modparam: yes -> enable: MST

<7> [793.630875] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 01 21 03 7f 3b 07 01 00 00 1f 0e 11 08 00 00 00

<7> [793.631747] xe 0000:00:02.0: [drm:intel_dp_get_dsc_sink_cap [xe]] FEC CAPABILITY: ff

<7> [793.632593] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000, 1000000, 2000000

<7> [793.632692] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 270000, 540000, 810000, 1000000

<7> [793.632775] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 270000, 540000, 810000, 1000000

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

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

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

<7> [793.633434] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PICA_TC

<7> [793.633530] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC1

<7> [793.633681] 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> [793.633782] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:226:DP-2] disconnected

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

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

<7> [793.634235] 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> [793.634323] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:234:DP-3] disconnected

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

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

<7> [793.635304] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 01 21 00 76 0a 02 01 80 00 01 06 66 08 00 00 00

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

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

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

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

<7> [793.635924] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:205:eDP-1] DisplayID extension version 0x20, primary use 0x02

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

<7> [793.635929] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:205:eDP-1] ELD monitor NE160QDM-NZ7

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

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

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

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

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

<7> [793.636829] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1600": 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 0x48 0xa

<7> [793.636833] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1600": 60 293760 2560 2608 2640 2720 1600 1663 1669 1800 0x48 0xa

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

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

<7> [793.637039] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC1

<7> [793.638057] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PICA_TC

<7> [793.641443] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Base DPCD: 12 14 c4 81 01 01 03 80 02 02 06 00 00 00 81

<7> [793.641464] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DPCD: 14 1e c4 81 01 00 03 80 02 02 06 00 00 00 81

<7> [793.642225] xe 0000:00:02.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:214:DP-1][ENCODER:213:DDI TC1/PHY TC1][DPRX] LTTPR common capabilities: 20 1e 80 aa 04 00 01 03

<7> [793.644496] xe 0000:00:02.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:214:DP-1][ENCODER:213:DDI TC1/PHY TC1][LTTPR 1] PHY capabilities: 04 00 00

<7> [793.645349] xe 0000:00:02.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: LTTPR 1: OUI 98-4f-ee dev-ID HBR HW-rev 10.2 SW-rev 2.11 quirks 0x0000

<7> [793.648035] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: Base DPCD: 12 14 c4 81 01 01 03 80 02 02 06 00 00 00 81

<7> [793.648047] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DPCD: 14 1e c4 81 01 00 03 80 02 02 06 00 00 00 81

<7> [793.648812] xe 0000:00:02.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX USBC1/DDI TC1/PHY TC1: DP sink: OUI 00-0c-e7 dev-ID HW-rev 0.0 SW-rev 0.0 quirks 0x0020

<7> [793.651016] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [ENCODER:213:DDI TC1/PHY TC1] MST support: port: yes, sink: MST, modparam: yes -> enable: MST

<7> [793.658405] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 01 21 03 7f 3b 07 01 00 00 1f 0e 11 08 00 00 00

<7> [793.659239] xe 0000:00:02.0: [drm:intel_dp_get_dsc_sink_cap [xe]] FEC CAPABILITY: ff

<7> [793.660024] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000, 1000000, 2000000

<7> [793.660110] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 270000, 540000, 810000, 1000000

<7> [793.660192] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 270000, 540000, 810000, 1000000

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

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

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

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

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

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

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

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

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

<7> [793.664441] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:242]

<7> [793.664805] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:244]

<7> [793.740093] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PICA_TC

<7> [793.740354] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC1

<7> [793.743903] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:88:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [793.749391] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no)

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

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

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

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

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

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

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

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

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

<7> [793.750527] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:83:cursor A] ddb (3942 - 4096) -> ( 0 - 0), size 154 -> 0

<7> [793.750599] 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> [793.750670] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] lines 4, 46, 46, 46, 43, 46, 0, 0, 0, 9, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [793.750736] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] blocks 85, 967, 967, 967, 904, 967, 0, 0, 99, 190, 204 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [793.750801] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] min_ddb 95,1065,1065,1065, 996,1065, 0, 0, 100, 210, 210 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [793.750897] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:88:pipe A] data rate 0 num active planes 0

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

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

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

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

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

<7> [793.751537] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] Can change cdclk via crawling and squashing

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

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

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

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

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

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

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

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

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

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

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

<7> [793.753323] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling Panel Replay

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [794.032282] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:88:pipe A]

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

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

<7> [794.033534] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:145:pipe B]

<7> [794.033821] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:202:pipe C]

<7> [794.034114] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:88:pipe A]

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

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

<7> [794.034691] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:204:DDI A/PHY A][CRTC:88:pipe A] DP link limits: pixel clock 1175040 kHz DSC off max lanes 4 max rate 675000 max pipe_bpp 30 max link_bpp 30.0000

<7> [794.034944] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 675000 bpp input 18 compressed 0.0000 link rate required 2643840 available 2700000

<7> [794.035232] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:88:pipe A] hw max bpp: 30, pipe bpp: 18, dithering: 1

<7> [794.035495] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:204:DDI A/PHY A] [CRTC:88:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [794.043461] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:88:pipe A] fastset requirement not met in enhanced_framing (expected no, found yes)

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

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

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

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

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

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

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

<7> [794.044936] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:83:cursor A] ddb ( 0 - 0) -> (3942 - 4096), size 0 -> 154

<7> [794.045067] 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> [794.045177] 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, 46, 46, 46, 43, 46, 0, 0, 0, 9, 0

<7> [794.045282] 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 -> 82, 933, 933, 933, 872, 933, 0, 0, 177, 184, 198

<7> [794.045390] 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 -> 163,1054,1054,1054, 973,1054, 0, 0, 178, 325, 325

<7> [794.045530] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:88:pipe A] data rate 4700160 num active planes 1

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

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

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

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

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

<7> [794.046693] xe 0000:00:02.0: [drm:intel_plane_calc_min_cdclk [xe]] [PLANE:33:plane 1A] min cdclk (587520 kHz) > [CRTC:88:pipe A] min cdclk (0 kHz)

<7> [794.046852] xe 0000:00:02.0: [drm:intel_bw_calc_min_cdclk [xe]] new bandwidth min cdclk (91800 kHz) > old min cdclk (0 kHz)

<7> [794.047070] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] Can change cdclk via crawling and squashing

<7> [794.047271] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 612000 kHz, actual 612000 kHz

<7> [794.047462] xe 0000:00:02.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 3, actual 3

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

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

<7> [794.048139] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 18, dithering: 1

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

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

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

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

<7> [794.049242] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 8214124, data_n: 8388608, link_m: 912680, link_n: 524288, tu: 64

<7> [794.049474] 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> [794.049705] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled

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

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

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

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

<7> [794.050978] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 6, length 16

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

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

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

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

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

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

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

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

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

<7> [794.052731] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vblank delay: 0, framestart delay: 1, MSA timing delay: 0

<7> [794.052985] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1800, vmax: 1800, flipline: 1800, pipeline full: 0, guardband: 200 vsync start: 137, vsync end: 131

<7> [794.053236] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1600, vmax vblank: 1600, vmin vtotal: 1800, vmax vtotal: 1800

<7> [794.053481] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2560x1600": 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 0x48 0xa

<7> [794.053729] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2560x1600": 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 0x48 0xa

<7> [794.053992] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=1175040, hd=2560 hb=2560-2720 hs=2608-2640 ht=2720, vd=1600 vb=1600-1800 vs=1663-1669 vt=1800, flags=0xa

<7> [794.054247] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2560x1600": 240 1175040 2560 2608 2640 2720 1600 1663 1669 1800 0x40 0xa

<7> [794.054496] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=1175040, hd=2560 hb=2560-2720 hs=2608-2640 ht=2720, vd=1600 vb=1600-1800 vs=1663-1669 vt=1800, flags=0xa

<7> [794.054743] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 675000, pipe src: 2560x1600+0+0, pixel rate 1175040

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

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

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

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

<7> [794.056019] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dpll_hw_state: dpll: 0xa4cb8, dpll_md: 0xb42110, fp0: 0x13e, fp1: 0x1000000

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [794.059233] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2560.000000x1600.000000+0.000000+0.000000 dst: 2560x1600+0+0

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

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

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

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

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

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

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

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

<7> [794.061521] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 612000 kHz, VCO 1305600 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 3

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [794.542220] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 PP_STATUS: 0x00000000 PP_CONTROL: 0x00000068

<7> [794.542445] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 panel power wasn't enabled

<7> [794.724008] 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> [794.723997] 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> [794.724049] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (dp-alt -> disconnected) pin assignment: E max lanes: 4

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

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

<7> [794.749028] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:204:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x00000000 PP_CONTROL: 0x00000068

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

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

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

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

<7> [794.976361] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e c4 c1 00 00 01 c0 02 00 02 00 08 09 84

<7> [794.978029] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Reloading eDP link rates

<7> [794.978852] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:205:eDP-1][ENCODER:204:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 07

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

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

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

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

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

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

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

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

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

<7> [795.002797] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:205:eDP-1] set backlight PWM = 13892

<7> [795.003333] xe 0000:00:02.0: [drm:i915_hotplug_work_func [xe]] running encoder hotplug functions

<7> [795.006273] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling Panel Replay

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

<7> [795.008509] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:88:pipe A]

<3> [795.437495] usb usb4-port1: Cannot enable. Maybe the USB cable is bad?

<4> [795.437606] usb usb4-port1: config error

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

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

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

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

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

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

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