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

Detail	Value
Duration	4.36 seconds
Hostname	shard-lnl-4
Igt-Version	IGT-Version: 2.3-g181486245 (x86_64) (Linux: 7.0.0-rc5-lgci-xe-xe-4811-d699fa2d9776038b1-debug+ x86_64)
Out	Using IGT_SRANDOM=1774698594 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:925 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1891 run_test() #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047() #4 ../tests/kms_flip.c:2047 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (4.361s)
Err	Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 (kms_flip:6415) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:930: (kms_flip:6415) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:6415) DEBUG: name = flip last_ts = 369.823364 last_received_ts = 369.822540 last_seq = 3751 current_ts = 369.840027 current_received_ts = 369.839203 current_seq = 3752 count = 57 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 56us (kms_flip:6415) DEBUG: name = flip last_ts = 369.840027 last_received_ts = 369.839203 last_seq = 3752 current_ts = 369.856689 current_received_ts = 369.855865 current_seq = 3753 count = 58 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 56us (kms_flip:6415) DEBUG: name = flip last_ts = 369.856689 last_received_ts = 369.855865 last_seq = 3753 current_ts = 369.873352 current_received_ts = 369.872559 current_seq = 3754 count = 59 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 57us (kms_flip:6415) DEBUG: name = flip last_ts = 369.873352 last_received_ts = 369.872559 last_seq = 3754 current_ts = 369.890015 current_received_ts = 369.889191 current_seq = 3755 count = 60 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 58us (kms_flip:6415) DEBUG: name = flip last_ts = 369.890015 last_received_ts = 369.889191 last_seq = 3755 current_ts = 369.906677 current_received_ts = 369.905853 current_seq = 3756 count = 61 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 55us (kms_flip:6415) DEBUG: name = flip last_ts = 369.906677 last_received_ts = 369.905853 last_seq = 3756 current_ts = 369.923340 current_received_ts = 369.922546 current_seq = 3757 count = 62 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 55us (kms_flip:6415) DEBUG: name = flip last_ts = 369.923340 last_received_ts = 369.922546 last_seq = 3757 current_ts = 369.940002 current_received_ts = 369.939178 current_seq = 3758 count = 63 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 41us (kms_flip:6415) DEBUG: name = flip last_ts = 369.940002 last_received_ts = 369.939178 last_seq = 3758 current_ts = 369.956665 current_received_ts = 369.955872 current_seq = 3759 count = 64 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 55us (kms_flip:6415) DEBUG: name = flip last_ts = 369.956665 last_received_ts = 369.955872 last_seq = 3759 current_ts = 369.973328 current_received_ts = 369.972534 current_seq = 3760 count = 65 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 56us (kms_flip:6415) DEBUG: name = flip last_ts = 369.973328 last_received_ts = 369.972534 last_seq = 3760 current_ts = 369.989990 current_received_ts = 369.989166 current_seq = 3761 count = 66 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 55us (kms_flip:6415) DEBUG: name = flip last_ts = 369.989990 last_received_ts = 369.989166 last_seq = 3761 current_ts = 370.006653 current_received_ts = 370.005859 current_seq = 3762 count = 67 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 55us (kms_flip:6415) DEBUG: name = flip last_ts = 370.006653 last_received_ts = 370.005859 last_seq = 3762 current_ts = 370.023315 current_received_ts = 370.022522 current_seq = 3763 count = 68 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 56us (kms_flip:6415) DEBUG: name = flip last_ts = 370.023315 last_received_ts = 370.022522 last_seq = 3763 current_ts = 370.040009 current_received_ts = 370.039520 current_seq = 3764 count = 69 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 82us (kms_flip:6415) DEBUG: name = flip last_ts = 370.040009 last_received_ts = 370.039520 last_seq = 3764 current_ts = 370.056671 current_received_ts = 370.055908 current_seq = 3765 count = 70 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 76us (kms_flip:6415) DEBUG: name = flip last_ts = 370.056671 last_received_ts = 370.055908 last_seq = 3765 current_ts = 370.073334 current_received_ts = 370.072540 current_seq = 3766 count = 71 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 66us (kms_flip:6415) DEBUG: name = flip last_ts = 370.073334 last_received_ts = 370.072540 last_seq = 3766 current_ts = 370.089996 current_received_ts = 370.089203 current_seq = 3767 count = 72 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 62us (kms_flip:6415) DEBUG: name = flip last_ts = 370.089996 last_received_ts = 370.089203 last_seq = 3767 current_ts = 370.106659 current_received_ts = 370.105927 current_seq = 3768 count = 73 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 136us (kms_flip:6415) DEBUG: name = flip last_ts = 370.106659 last_received_ts = 370.105927 last_seq = 3768 current_ts = 370.123322 current_received_ts = 370.122589 current_seq = 3769 count = 74 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 125us (kms_flip:6415) DEBUG: name = flip last_ts = 370.123322 last_received_ts = 370.122589 last_seq = 3769 current_ts = 370.139984 current_received_ts = 370.139221 current_seq = 3770 count = 75 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 125us (kms_flip:6415) DEBUG: name = flip last_ts = 370.139984 last_received_ts = 370.139221 last_seq = 3770 current_ts = 370.156647 current_received_ts = 370.155975 current_seq = 3771 count = 76 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 105us (kms_flip:6415) DEBUG: name = flip last_ts = 370.156647 last_received_ts = 370.155975 last_seq = 3771 current_ts = 370.173309 current_received_ts = 370.172668 current_seq = 3772 count = 77 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 84us (kms_flip:6415) DEBUG: name = flip last_ts = 370.173309 last_received_ts = 370.172668 last_seq = 3772 current_ts = 370.189972 current_received_ts = 370.189240 current_seq = 3773 count = 78 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 88us (kms_flip:6415) DEBUG: name = flip last_ts = 370.189972 last_received_ts = 370.189240 last_seq = 3773 current_ts = 370.206635 current_received_ts = 370.205902 current_seq = 3774 count = 79 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 121us (kms_flip:6415) DEBUG: name = flip last_ts = 370.206635 last_received_ts = 370.205902 last_seq = 3774 current_ts = 370.223297 current_received_ts = 370.222534 current_seq = 3775 count = 80 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 62us (kms_flip:6415) DEBUG: name = flip last_ts = 370.223297 last_received_ts = 370.222534 last_seq = 3775 current_ts = 370.239960 current_received_ts = 370.239197 current_seq = 3776 count = 81 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 56us (kms_flip:6415) DEBUG: name = flip last_ts = 370.239960 last_received_ts = 370.239197 last_seq = 3776 current_ts = 370.256622 current_received_ts = 370.255981 current_seq = 3777 count = 82 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 142us (kms_flip:6415) DEBUG: name = flip last_ts = 370.256622 last_received_ts = 370.255981 last_seq = 3777 current_ts = 370.273315 current_received_ts = 370.272614 current_seq = 3778 count = 83 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 92us (kms_flip:6415) DEBUG: name = flip last_ts = 370.273315 last_received_ts = 370.272614 last_seq = 3778 current_ts = 370.289978 current_received_ts = 370.289368 current_seq = 3779 count = 84 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 91us (kms_flip:6415) DEBUG: name = flip last_ts = 370.289978 last_received_ts = 370.289368 last_seq = 3779 current_ts = 370.306641 current_received_ts = 370.305969 current_seq = 3780 count = 85 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 102us (kms_flip:6415) DEBUG: name = flip last_ts = 370.306641 last_received_ts = 370.305969 last_seq = 3780 current_ts = 370.323303 current_received_ts = 370.322601 current_seq = 3781 count = 86 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 113us (kms_flip:6415) DEBUG: name = flip last_ts = 370.323303 last_received_ts = 370.322601 last_seq = 3781 current_ts = 370.339966 current_received_ts = 370.339203 current_seq = 3782 count = 87 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 56us (kms_flip:6415) DEBUG: name = flip last_ts = 370.339966 last_received_ts = 370.339203 last_seq = 3782 current_ts = 370.356628 current_received_ts = 370.355988 current_seq = 3783 count = 88 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 92us (kms_flip:6415) DEBUG: name = flip last_ts = 370.356628 last_received_ts = 370.355988 last_seq = 3783 current_ts = 370.373291 current_received_ts = 370.372620 current_seq = 3784 count = 89 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 101us (kms_flip:6415) DEBUG: name = flip last_ts = 370.373291 last_received_ts = 370.372620 last_seq = 3784 current_ts = 370.389954 current_received_ts = 370.389496 current_seq = 3785 count = 90 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 100us (kms_flip:6415) DEBUG: name = flip last_ts = 370.389954 last_received_ts = 370.389496 last_seq = 3785 current_ts = 370.406616 current_received_ts = 370.405914 current_seq = 3786 count = 91 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 61us (kms_flip:6415) DEBUG: name = flip last_ts = 370.406616 last_received_ts = 370.405914 last_seq = 3786 current_ts = 370.423279 current_received_ts = 370.422791 current_seq = 3787 count = 92 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 35us (kms_flip:6415) DEBUG: name = flip last_ts = 370.423279 last_received_ts = 370.422791 last_seq = 3787 current_ts = 370.439941 current_received_ts = 370.439514 current_seq = 3788 count = 93 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 36us (kms_flip:6415) DEBUG: name = flip last_ts = 370.439941 last_received_ts = 370.439514 last_seq = 3788 current_ts = 370.456604 current_received_ts = 370.455902 current_seq = 3789 count = 94 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 62us (kms_flip:6415) DEBUG: name = flip last_ts = 370.456604 last_received_ts = 370.455902 last_seq = 3789 current_ts = 370.473267 current_received_ts = 370.472717 current_seq = 3790 count = 95 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 91us (kms_flip:6415) DEBUG: name = flip last_ts = 370.473267 last_received_ts = 370.472717 last_seq = 3790 current_ts = 370.489929 current_received_ts = 370.489258 current_seq = 3791 count = 96 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 91us (kms_flip:6415) DEBUG: name = flip last_ts = 370.489929 last_received_ts = 370.489258 last_seq = 3791 current_ts = 370.506592 current_received_ts = 370.506073 current_seq = 3792 count = 97 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 79us (kms_flip:6415) DEBUG: name = flip last_ts = 370.506592 last_received_ts = 370.506073 last_seq = 3792 current_ts = 370.523285 current_received_ts = 370.522614 current_seq = 3793 count = 98 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 85us (kms_flip:6415) DEBUG: name = flip last_ts = 370.523285 last_received_ts = 370.522614 last_seq = 3793 current_ts = 370.539948 current_received_ts = 370.539215 current_seq = 3794 count = 99 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 113us (kms_flip:6415) DEBUG: name = flip last_ts = 370.539948 last_received_ts = 370.539215 last_seq = 3794 current_ts = 370.556610 current_received_ts = 370.556244 current_seq = 3795 count = 100 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 73us (kms_flip:6415) DEBUG: name = flip last_ts = 370.556610 last_received_ts = 370.556244 last_seq = 3795 current_ts = 370.573273 current_received_ts = 370.572845 current_seq = 3796 count = 101 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 81us (kms_flip:6415) DEBUG: name = flip last_ts = 370.573273 last_received_ts = 370.572845 last_seq = 3796 current_ts = 370.589935 current_received_ts = 370.589294 current_seq = 3797 count = 102 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 90us (kms_flip:6415) DEBUG: name = flip last_ts = 370.589935 last_received_ts = 370.589294 last_seq = 3797 current_ts = 370.606598 current_received_ts = 370.605927 current_seq = 3798 count = 103 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 124us (kms_flip:6415) DEBUG: name = flip last_ts = 370.606598 last_received_ts = 370.605927 last_seq = 3798 current_ts = 370.623260 current_received_ts = 370.622772 current_seq = 3799 count = 104 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 43us (kms_flip:6415) DEBUG: name = flip last_ts = 370.623260 last_received_ts = 370.622772 last_seq = 3799 current_ts = 370.639923 current_received_ts = 370.639221 current_seq = 3800 count = 105 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 62us (kms_flip:6415) DEBUG: name = flip last_ts = 370.639923 last_received_ts = 370.639221 last_seq = 3800 current_ts = 370.656586 current_received_ts = 370.655975 current_seq = 3801 count = 106 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 97us (kms_flip:6415) DEBUG: name = flip last_ts = 370.656586 last_received_ts = 370.655975 last_seq = 3801 current_ts = 370.673248 current_received_ts = 370.672607 current_seq = 3802 count = 107 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 89us (kms_flip:6415) DEBUG: name = flip last_ts = 370.673248 last_received_ts = 370.672607 last_seq = 3802 current_ts = 370.689911 current_received_ts = 370.689209 current_seq = 3803 count = 108 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 114us (kms_flip:6415) DEBUG: name = flip last_ts = 370.689911 last_received_ts = 370.689209 last_seq = 3803 current_ts = 370.706573 current_received_ts = 370.705994 current_seq = 3804 count = 109 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 93us (kms_flip:6415) DEBUG: name = flip last_ts = 370.706573 last_received_ts = 370.705994 last_seq = 3804 current_ts = 370.723236 current_received_ts = 370.722595 current_seq = 3805 count = 110 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 102us (kms_flip:6415) DEBUG: name = flip last_ts = 370.723236 last_received_ts = 370.722595 last_seq = 3805 current_ts = 370.739899 current_received_ts = 370.739197 current_seq = 3806 count = 111 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 106us (kms_flip:6415) DEBUG: name = flip last_ts = 370.739899 last_received_ts = 370.739197 last_seq = 3806 current_ts = 370.756561 current_received_ts = 370.755981 current_seq = 3807 count = 112 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 131us (kms_flip:6415) DEBUG: name = flip last_ts = 370.756561 last_received_ts = 370.755981 last_seq = 3807 current_ts = 370.773254 current_received_ts = 370.772858 current_seq = 3808 count = 113 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 100us (kms_flip:6415) DEBUG: name = flip last_ts = 370.773254 last_received_ts = 370.772858 last_seq = 3808 current_ts = 370.789917 current_received_ts = 370.789185 current_seq = 3809 count = 114 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 109us (kms_flip:6415) DEBUG: name = flip last_ts = 370.789917 last_received_ts = 370.789185 last_seq = 3809 current_ts = 370.806580 current_received_ts = 370.805939 current_seq = 3810 count = 115 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 111us (kms_flip:6415) DEBUG: name = flip last_ts = 370.806580 last_received_ts = 370.805939 last_seq = 3810 current_ts = 370.823242 current_received_ts = 370.822693 current_seq = 3811 count = 116 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 83us (kms_flip:6415) DEBUG: name = flip last_ts = 370.823242 last_received_ts = 370.822693 last_seq = 3811 current_ts = 370.839905 current_received_ts = 370.839478 current_seq = 3812 count = 117 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 92us (kms_flip:6415) DEBUG: name = flip last_ts = 370.839905 last_received_ts = 370.839478 last_seq = 3812 current_ts = 370.856567 current_received_ts = 370.855865 current_seq = 3813 count = 118 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 65us (kms_flip:6415) DEBUG: name = flip last_ts = 370.856567 last_received_ts = 370.855865 last_seq = 3813 current_ts = 370.873230 current_received_ts = 370.872498 current_seq = 3814 count = 119 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 51us (kms_flip:6415) DEBUG: name = flip last_ts = 370.873230 last_received_ts = 370.872498 last_seq = 3814 current_ts = 370.889893 current_received_ts = 370.889160 current_seq = 3815 count = 120 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 60us (kms_flip:6415) DEBUG: name = flip last_ts = 370.889893 last_received_ts = 370.889160 last_seq = 3815 current_ts = 370.906555 current_received_ts = 370.905945 current_seq = 3816 count = 121 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 132us (kms_flip:6415) DEBUG: name = flip last_ts = 370.906555 last_received_ts = 370.905945 last_seq = 3816 current_ts = 370.923218 current_received_ts = 370.922546 current_seq = 3817 count = 122 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 107us (kms_flip:6415) DEBUG: name = flip last_ts = 370.923218 last_received_ts = 370.922546 last_seq = 3817 current_ts = 370.939880 current_received_ts = 370.939209 current_seq = 3818 count = 123 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 119us (kms_flip:6415) DEBUG: name = flip last_ts = 370.939880 last_received_ts = 370.939209 last_seq = 3818 current_ts = 370.956543 current_received_ts = 370.956238 current_seq = 3819 count = 124 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 80us (kms_flip:6415) DEBUG: name = flip last_ts = 370.956543 last_received_ts = 370.956238 last_seq = 3819 current_ts = 370.973236 current_received_ts = 370.972900 current_seq = 3820 count = 125 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 112us (kms_flip:6415) DEBUG: name = flip last_ts = 370.973236 last_received_ts = 370.972900 last_seq = 3820 current_ts = 370.989899 current_received_ts = 370.989227 current_seq = 3821 count = 126 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 88us (kms_flip:6415) DEBUG: name = flip last_ts = 370.989899 last_received_ts = 370.989227 last_seq = 3821 current_ts = 371.006531 current_received_ts = 371.005798 current_seq = 3822 count = 127 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 115us (kms_flip:6415) DEBUG: name = flip last_ts = 371.006531 last_received_ts = 371.005798 last_seq = 3822 current_ts = 371.023224 current_received_ts = 371.022583 current_seq = 3823 count = 128 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 78us (kms_flip:6415) DEBUG: name = flip last_ts = 371.023224 last_received_ts = 371.022583 last_seq = 3823 current_ts = 371.039886 current_received_ts = 371.039215 current_seq = 3824 count = 129 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 80us (kms_flip:6415) DEBUG: name = flip last_ts = 371.039886 last_received_ts = 371.039215 last_seq = 3824 current_ts = 371.056549 current_received_ts = 371.055878 current_seq = 3825 count = 130 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 78us (kms_flip:6415) DEBUG: name = flip last_ts = 371.056549 last_received_ts = 371.055878 last_seq = 3825 current_ts = 371.073212 current_received_ts = 371.072540 current_seq = 3826 count = 131 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 96us (kms_flip:6415) DEBUG: name = flip last_ts = 371.073212 last_received_ts = 371.072540 last_seq = 3826 current_ts = 371.089874 current_received_ts = 371.089172 current_seq = 3827 count = 132 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 107us (kms_flip:6415) DEBUG: name = flip last_ts = 371.089874 last_received_ts = 371.089172 last_seq = 3827 current_ts = 371.106537 current_received_ts = 371.105957 current_seq = 3828 count = 133 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 130us (kms_flip:6415) DEBUG: name = flip last_ts = 371.106537 last_received_ts = 371.105957 last_seq = 3828 current_ts = 371.123199 current_received_ts = 371.122559 current_seq = 3829 count = 134 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 116us (kms_flip:6415) DEBUG: name = flip last_ts = 371.123199 last_received_ts = 371.122559 last_seq = 3829 current_ts = 371.139862 current_received_ts = 371.139191 current_seq = 3830 count = 135 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 101us (kms_flip:6415) DEBUG: name = flip last_ts = 371.139862 last_received_ts = 371.139191 last_seq = 3830 current_ts = 371.156525 current_received_ts = 371.155945 current_seq = 3831 count = 136 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 113us (kms_flip:6415) DEBUG: name = flip last_ts = 371.156525 last_received_ts = 371.155945 last_seq = 3831 current_ts = 371.173187 current_received_ts = 371.172546 current_seq = 3832 count = 137 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 96us (kms_flip:6415) DEBUG: name = flip last_ts = 371.173187 last_received_ts = 371.172546 last_seq = 3832 current_ts = 371.189850 current_received_ts = 371.189148 current_seq = 3833 count = 138 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 62us (kms_flip:6415) DEBUG: name = flip last_ts = 371.189850 last_received_ts = 371.189148 last_seq = 3833 current_ts = 371.206512 current_received_ts = 371.205811 current_seq = 3834 count = 139 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 64us (kms_flip:6415) DEBUG: name = flip last_ts = 371.206512 last_received_ts = 371.205811 last_seq = 3834 current_ts = 371.223175 current_received_ts = 371.222534 current_seq = 3835 count = 140 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 92us (kms_flip:6415) DEBUG: name = flip last_ts = 371.223175 last_received_ts = 371.222534 last_seq = 3835 current_ts = 371.239838 current_received_ts = 371.239288 current_seq = 3836 count = 141 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 80us (kms_flip:6415) DEBUG: name = flip last_ts = 371.239838 last_received_ts = 371.239288 last_seq = 3836 current_ts = 371.256531 current_received_ts = 371.255859 current_seq = 3837 count = 142 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 88us (kms_flip:6415) DEBUG: name = flip last_ts = 371.256531 last_received_ts = 371.255859 last_seq = 3837 current_ts = 371.273193 current_received_ts = 371.272491 current_seq = 3838 count = 143 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 63us (kms_flip:6415) DEBUG: name = flip last_ts = 371.273193 last_received_ts = 371.272491 last_seq = 3838 current_ts = 371.289856 current_received_ts = 371.289154 current_seq = 3839 count = 144 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 61us (kms_flip:6415) DEBUG: name = flip last_ts = 371.289856 last_received_ts = 371.289154 last_seq = 3839 current_ts = 371.306519 current_received_ts = 371.305878 current_seq = 3840 count = 145 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 81us (kms_flip:6415) DEBUG: name = flip last_ts = 371.306519 last_received_ts = 371.305878 last_seq = 3840 current_ts = 371.323181 current_received_ts = 371.322510 current_seq = 3841 count = 146 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 85us (kms_flip:6415) DEBUG: name = flip last_ts = 371.323181 last_received_ts = 371.322510 last_seq = 3841 current_ts = 371.339844 current_received_ts = 371.339081 current_seq = 3842 count = 147 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 63us (kms_flip:6415) DEBUG: name = flip last_ts = 371.339844 last_received_ts = 371.339081 last_seq = 3842 current_ts = 371.356506 current_received_ts = 371.356140 current_seq = 3843 count = 148 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 92us (kms_flip:6415) DEBUG: name = flip last_ts = 371.356506 last_received_ts = 371.356140 last_seq = 3843 current_ts = 371.373169 current_received_ts = 371.372864 current_seq = 3844 count = 149 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 100us (kms_flip:6415) DEBUG: name = flip last_ts = 371.373169 last_received_ts = 371.372864 last_seq = 3844 current_ts = 371.389832 current_received_ts = 371.389282 current_seq = 3845 count = 150 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 135us (kms_flip:6415) DEBUG: name = flip last_ts = 371.389832 last_received_ts = 371.389282 last_seq = 3845 current_ts = 371.406494 current_received_ts = 371.405914 current_seq = 3846 count = 151 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 109us (kms_flip:6415) DEBUG: name = flip last_ts = 371.406494 last_received_ts = 371.405914 last_seq = 3846 current_ts = 371.423157 current_received_ts = 371.422516 current_seq = 3847 count = 152 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 92us (kms_flip:6415) DEBUG: name = flip last_ts = 371.423157 last_received_ts = 371.422516 last_seq = 3847 current_ts = 371.439819 current_received_ts = 371.439209 current_seq = 3848 count = 153 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 88us (kms_flip:6415) DEBUG: name = flip last_ts = 371.439819 last_received_ts = 371.439209 last_seq = 3848 current_ts = 371.456482 current_received_ts = 371.455872 current_seq = 3849 count = 154 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 98us (kms_flip:6415) DEBUG: name = flip last_ts = 371.456482 last_received_ts = 371.455872 last_seq = 3849 current_ts = 371.473145 current_received_ts = 371.472534 current_seq = 3850 count = 155 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 87us (kms_flip:6415) DEBUG: name = flip last_ts = 371.473145 last_received_ts = 371.472534 last_seq = 3850 current_ts = 371.489807 current_received_ts = 371.489197 current_seq = 3851 count = 156 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 100us (kms_flip:6415) DEBUG: name = flip last_ts = 371.489807 last_received_ts = 371.489197 last_seq = 3851 current_ts = 371.506470 current_received_ts = 371.505859 current_seq = 3852 count = 157 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 100us (kms_flip:6415) DEBUG: name = flip last_ts = 371.506470 last_received_ts = 371.505859 last_seq = 3852 current_ts = 371.523132 current_received_ts = 371.522522 current_seq = 3853 count = 158 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 99us (kms_flip:6415) DEBUG: name = flip last_ts = 371.523132 last_received_ts = 371.522522 last_seq = 3853 current_ts = 371.539825 current_received_ts = 371.539185 current_seq = 3854 count = 159 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 95us (kms_flip:6415) DEBUG: name = flip last_ts = 371.539825 last_received_ts = 371.539185 last_seq = 3854 current_ts = 371.556488 current_received_ts = 371.555847 current_seq = 3855 count = 160 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 85us (kms_flip:6415) DEBUG: name = flip last_ts = 371.556488 last_received_ts = 371.555847 last_seq = 3855 current_ts = 371.573151 current_received_ts = 371.572510 current_seq = 3856 count = 161 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 90us (kms_flip:6415) DEBUG: name = flip last_ts = 371.573151 last_received_ts = 371.572510 last_seq = 3856 current_ts = 371.589813 current_received_ts = 371.589172 current_seq = 3857 count = 162 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 100us (kms_flip:6415) DEBUG: name = flip last_ts = 371.589813 last_received_ts = 371.589172 last_seq = 3857 current_ts = 371.606476 current_received_ts = 371.605835 current_seq = 3858 count = 163 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 86us (kms_flip:6415) DEBUG: name = flip last_ts = 371.606476 last_received_ts = 371.605835 last_seq = 3858 current_ts = 371.623138 current_received_ts = 371.622498 current_seq = 3859 count = 164 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 99us (kms_flip:6415) DEBUG: name = flip last_ts = 371.623138 last_received_ts = 371.622498 last_seq = 3859 current_ts = 371.639801 current_received_ts = 371.639160 current_seq = 3860 count = 165 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 99us (kms_flip:6415) DEBUG: name = flip last_ts = 371.639801 last_received_ts = 371.639160 last_seq = 3860 current_ts = 371.656464 current_received_ts = 371.655945 current_seq = 3861 count = 166 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 114us (kms_flip:6415) DEBUG: name = flip last_ts = 371.656464 last_received_ts = 371.655945 last_seq = 3861 current_ts = 371.673126 current_received_ts = 371.672577 current_seq = 3862 count = 167 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 99us (kms_flip:6415) DEBUG: name = flip last_ts = 371.673126 last_received_ts = 371.672577 last_seq = 3862 current_ts = 371.689789 current_received_ts = 371.689209 current_seq = 3863 count = 168 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 99us (kms_flip:6415) DEBUG: name = flip last_ts = 371.689789 last_received_ts = 371.689209 last_seq = 3863 current_ts = 371.706451 current_received_ts = 371.705902 current_seq = 3864 count = 169 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 120us (kms_flip:6415) DEBUG: name = flip last_ts = 371.706451 last_received_ts = 371.705902 last_seq = 3864 current_ts = 371.723114 current_received_ts = 371.722595 current_seq = 3865 count = 170 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 87us (kms_flip:6415) DEBUG: name = flip last_ts = 371.723114 last_received_ts = 371.722595 last_seq = 3865 current_ts = 371.739777 current_received_ts = 371.739227 current_seq = 3866 count = 171 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 86us (kms_flip:6415) DEBUG: name = flip last_ts = 371.739777 last_received_ts = 371.739227 last_seq = 3866 current_ts = 371.756470 current_received_ts = 371.755890 current_seq = 3867 count = 172 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 127us (kms_flip:6415) DEBUG: name = flip last_ts = 371.756470 last_received_ts = 371.755890 last_seq = 3867 current_ts = 371.773102 current_received_ts = 371.772583 current_seq = 3868 count = 173 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 87us (kms_flip:6415) DEBUG: name = flip last_ts = 371.773102 last_received_ts = 371.772583 last_seq = 3868 current_ts = 371.789795 current_received_ts = 371.789215 current_seq = 3869 count = 174 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 87us (kms_flip:6415) DEBUG: name = flip last_ts = 371.789795 last_received_ts = 371.789215 last_seq = 3869 current_ts = 371.806458 current_received_ts = 371.805908 current_seq = 3870 count = 175 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 129us (kms_flip:6415) DEBUG: name = flip last_ts = 371.806458 last_received_ts = 371.805908 last_seq = 3870 current_ts = 371.823120 current_received_ts = 371.822571 current_seq = 3871 count = 176 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 87us (kms_flip:6415) DEBUG: name = flip last_ts = 371.823120 last_received_ts = 371.822571 last_seq = 3871 current_ts = 371.839783 current_received_ts = 371.839203 current_seq = 3872 count = 177 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 100us (kms_flip:6415) DEBUG: name = flip last_ts = 371.839783 last_received_ts = 371.839203 last_seq = 3872 current_ts = 371.856445 current_received_ts = 371.855865 current_seq = 3873 count = 178 seq_step = 1 (kms_flip:6415) DEBUG: Vblank took 514us (kms_flip:6415) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:930: (kms_flip:6415) CRITICAL: Failed assertion: end - start < 500 (kms_flip:6415) igt_core-INFO: Stack trace: (kms_flip:6415) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:6415) igt_core-INFO: #1 ../tests/kms_flip.c:925 run_test_on_crtc_set.constprop.0() (kms_flip:6415) igt_core-INFO: #2 ../tests/kms_flip.c:1891 run_test() (kms_flip:6415) igt_core-INFO: #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047() (kms_flip:6415) igt_core-INFO: #4 ../tests/kms_flip.c:2047 main() (kms_flip:6415) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:6415) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:6415) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (4.361s)
Dmesg	<6> [367.715480] Console: switching to colour dummy device 80x25 <6> [367.715829] [IGT] kms_flip: executing <7> [367.722380] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] <7> [367.722392] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1] <7> [367.722601] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected <7> [367.722951] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] <7> [367.722956] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2] <7> [367.723141] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected <7> [367.723507] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] <7> [367.723511] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3] <7> [367.723691] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected <7> [367.724177] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] <7> [367.724183] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:393:eDP-1] <7> [367.724716] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00 <7> [367.725114] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [367.725265] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [367.725555] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [367.726137] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz <5> [367.726161] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [367.726170] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [367.726175] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] DisplayID extension version 0x13, primary use 0x00 <7> [367.726191] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <5> [367.726204] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [367.726211] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD monitor <5> [367.726223] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [367.726229] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD size 20, SAD count 0 <5> [367.726240] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [367.726282] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] VRR capable: yes <7> [367.726505] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [367.726657] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <5> [367.727088] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [367.727091] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [367.727093] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [367.727181] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] probed modes: <7> [367.727186] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [367.727191] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [367.727210] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] <7> [367.727214] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1] <7> [367.727415] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected <7> [367.727429] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] <7> [367.727433] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2] <7> [367.727616] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected <7> [367.727629] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] <7> [367.727633] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3] <7> [367.727825] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected <6> [367.728588] [IGT] kms_flip: starting subtest flip-vs-expired-vblank <6> [367.730836] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [367.737484] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430] <7> [367.738177] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432] <7> [367.810005] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [367.810192] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [367.810439] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [367.810616] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [367.810911] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [367.811099] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0) <7> [367.811278] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [367.811431] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [367.811581] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [367.811726] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [367.812087] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [367.812248] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [367.812389] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [367.812522] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [367.812651] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [367.812825] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [367.812951] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [367.813074] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [367.813194] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [367.813312] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [367.813446] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [367.813592] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [367.813733] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [367.814371] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [367.814675] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [367.815055] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [367.815412] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [367.815550] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [367.815651] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [367.815756] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [367.815855] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [367.815948] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [367.816043] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [367.816135] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [367.816228] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [367.816320] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [367.816409] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [367.816495] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [367.816580] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0) <7> [367.816666] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [367.816762] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0 <7> [367.816891] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [367.816968] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [367.817064] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [367.817137] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [367.817201] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm <7> [367.817262] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [367.817328] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [367.817389] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [367.817464] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0 <7> [367.817557] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [367.817646] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [367.817737] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [367.817844] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [367.817934] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [367.818024] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [367.818149] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [367.818262] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [367.818367] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [367.818462] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [367.818571] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset] <7> [367.818659] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no <7> [367.818754] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [367.818858] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [367.818965] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [367.819069] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [367.819157] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [367.819288] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [367.819999] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [367.820139] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [367.820864] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [367.820984] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [368.028875] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0 <7> [368.029576] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [368.039143] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off <7> [368.039527] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time <7> [368.039970] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [368.091119] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [368.091515] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A] <7> [368.092127] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [368.092501] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short <7> [368.092814] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [368.093046] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [368.093550] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [368.094158] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A] <7> [368.094514] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1] <7> [368.094854] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A] <7> [368.095149] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B] <7> [368.095438] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C] <7> [368.095718] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2] <7> [368.096047] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A] <7> [368.096387] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B] <7> [368.096704] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C] <7> [368.097056] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3] <7> [368.097329] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A] <7> [368.097588] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B] <7> [368.097896] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C] <7> [368.098161] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1] <7> [368.098542] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [368.098908] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [368.099228] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [368.099788] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [368.100208] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000) <7> [368.100692] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [368.101095] 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> [368.101574] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [368.101910] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [368.102691] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B] <7> [368.103040] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C] <7> [368.103301] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [368.103362] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1] <7> [368.103520] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [368.103866] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000 <7> [368.104149] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000 <7> [368.104440] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [368.104704] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A] <7> [368.104997] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [368.105286] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [368.105522] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [368.105767] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [368.106021] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288) <7> [368.106240] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [368.106452] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [368.106681] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [368.106897] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [368.107116] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880) <7> [368.107312] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040) <7> [368.107489] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928) <7> [368.107658] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960) <7> [368.107860] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [368.108028] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800) <7> [368.108188] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803) <7> [368.108340] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809) <7> [368.108489] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [368.108632] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906) <7> [368.108791] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [368.108930] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [368.109069] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880) <7> [368.109206] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040) <7> [368.109340] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928) <7> [368.109476] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960) <7> [368.109611] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [368.109748] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800) <7> [368.109892] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803) <7> [368.110065] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809) <7> [368.110194] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [368.110315] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906) <7> [368.110431] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [368.110540] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [368.110648] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [368.110764] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [368.110871] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [368.110975] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [368.111084] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 432000) <7> [368.111194] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [368.111338] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [368.111428] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [368.111541] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [368.111628] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [368.111697] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm <7> [368.111782] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 <7> [368.111852] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 <7> [368.111930] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 <7> [368.112035] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1 <7> [368.112169] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [368.112286] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [368.112394] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [368.112503] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [368.112604] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [368.112694] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz <7> [368.112825] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [368.112955] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [368.113075] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [368.113174] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [368.113276] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0 <7> [368.113362] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0 <7> [368.113450] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset] <7> [368.113539] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [368.113621] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0 <7> [368.113702] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [368.113841] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [368.113946] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [368.114048] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [368.114133] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64 <7> [368.114214] 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> [368.114305] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [368.114398] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [368.114483] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [368.114562] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0 <7> [368.114642] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [368.114745] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [368.114843] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [368.114939] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [368.115035] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [368.115114] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [368.115189] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [368.115264] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [368.115340] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [368.115427] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97 <7> [368.115519] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906 <7> [368.115603] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [368.115680] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [368.115782] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [368.115885] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [368.115986] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [368.116085] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [368.116174] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855 <7> [368.116260] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [368.116352] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [368.116436] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [368.116515] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [368.116603] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no <7> [368.116701] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no, <7> [368.116813] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1. <7> [368.116910] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [368.117005] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [368.117093] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1 <7> [368.117191] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [368.117276] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [368.117354] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [368.117431] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23 <7> [368.117511] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [368.117589] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [368.117668] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [368.117748] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [368.117852] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [368.117959] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [368.118064] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [368.118150] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [368.118234] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [368.118320] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [368.118406] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [368.118486] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [368.118567] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [368.118641] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [368.118716] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [368.118825] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [368.118940] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [368.119055] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [368.119142] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [368.119220] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [368.119311] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [368.119713] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [368.119913] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000) <7> [368.120049] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [368.120158] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [368.120250] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [368.120339] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A] <7> [368.120414] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1] <7> [368.120486] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A] <7> [368.120552] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B] <7> [368.120622] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C] <7> [368.120699] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2] <7> [368.120799] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A] <7> [368.120882] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B] <7> [368.120963] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C] <7> [368.121042] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3] <7> [368.121120] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A] <7> [368.121187] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B] <7> [368.121251] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C] <7> [368.121331] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [368.121489] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [368.121558] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [368.121672] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [368.122762] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A] <7> [368.122897] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [368.124922] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on <7> [368.125031] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining) <7> [368.126368] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [368.126491] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long <7> [368.126580] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [368.126676] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [368.596957] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [368.607465] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [368.608123] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on <7> [368.608649] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [368.644343] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [368.644749] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long <7> [368.645107] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [368.645472] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [368.772897] 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> [368.772983] 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> [368.773124] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [368.823802] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [368.824251] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on <7> [368.824685] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [368.826995] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80 <7> [368.828546] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [368.829379] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05 <7> [368.830635] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [368.832096] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [368.833220] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK <7> [368.833625] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [368.835205] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [368.835572] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4 <7> [368.836391] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [368.836919] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [368.837301] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [368.837841] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 192000 <7> [368.853732] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [368.855792] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1] <7> [368.856357] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [371.397114] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off <7> [371.397804] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067 <7> [371.870802] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [371.871395] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [371.871929] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [372.093160] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

4.36 seconds

Hostname

shard-lnl-4

Igt-Version

IGT-Version: 2.3-g181486245 (x86_64) (Linux: 7.0.0-rc5-lgci-xe-xe-4811-d699fa2d9776038b1-debug+ x86_64)

Out

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

Err

Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
(kms_flip:6415) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:930:
(kms_flip:6415) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.823364
last_received_ts = 369.822540
last_seq = 3751
current_ts = 369.840027
current_received_ts = 369.839203
current_seq = 3752
count = 57
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 56us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.840027
last_received_ts = 369.839203
last_seq = 3752
current_ts = 369.856689
current_received_ts = 369.855865
current_seq = 3753
count = 58
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 56us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.856689
last_received_ts = 369.855865
last_seq = 3753
current_ts = 369.873352
current_received_ts = 369.872559
current_seq = 3754
count = 59
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 57us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.873352
last_received_ts = 369.872559
last_seq = 3754
current_ts = 369.890015
current_received_ts = 369.889191
current_seq = 3755
count = 60
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 58us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.890015
last_received_ts = 369.889191
last_seq = 3755
current_ts = 369.906677
current_received_ts = 369.905853
current_seq = 3756
count = 61
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 55us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.906677
last_received_ts = 369.905853
last_seq = 3756
current_ts = 369.923340
current_received_ts = 369.922546
current_seq = 3757
count = 62
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 55us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.923340
last_received_ts = 369.922546
last_seq = 3757
current_ts = 369.940002
current_received_ts = 369.939178
current_seq = 3758
count = 63
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 41us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.940002
last_received_ts = 369.939178
last_seq = 3758
current_ts = 369.956665
current_received_ts = 369.955872
current_seq = 3759
count = 64
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 55us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.956665
last_received_ts = 369.955872
last_seq = 3759
current_ts = 369.973328
current_received_ts = 369.972534
current_seq = 3760
count = 65
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 56us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.973328
last_received_ts = 369.972534
last_seq = 3760
current_ts = 369.989990
current_received_ts = 369.989166
current_seq = 3761
count = 66
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 55us
(kms_flip:6415) DEBUG: name = flip
last_ts = 369.989990
last_received_ts = 369.989166
last_seq = 3761
current_ts = 370.006653
current_received_ts = 370.005859
current_seq = 3762
count = 67
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 55us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.006653
last_received_ts = 370.005859
last_seq = 3762
current_ts = 370.023315
current_received_ts = 370.022522
current_seq = 3763
count = 68
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 56us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.023315
last_received_ts = 370.022522
last_seq = 3763
current_ts = 370.040009
current_received_ts = 370.039520
current_seq = 3764
count = 69
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 82us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.040009
last_received_ts = 370.039520
last_seq = 3764
current_ts = 370.056671
current_received_ts = 370.055908
current_seq = 3765
count = 70
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 76us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.056671
last_received_ts = 370.055908
last_seq = 3765
current_ts = 370.073334
current_received_ts = 370.072540
current_seq = 3766
count = 71
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 66us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.073334
last_received_ts = 370.072540
last_seq = 3766
current_ts = 370.089996
current_received_ts = 370.089203
current_seq = 3767
count = 72
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 62us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.089996
last_received_ts = 370.089203
last_seq = 3767
current_ts = 370.106659
current_received_ts = 370.105927
current_seq = 3768
count = 73
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 136us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.106659
last_received_ts = 370.105927
last_seq = 3768
current_ts = 370.123322
current_received_ts = 370.122589
current_seq = 3769
count = 74
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 125us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.123322
last_received_ts = 370.122589
last_seq = 3769
current_ts = 370.139984
current_received_ts = 370.139221
current_seq = 3770
count = 75
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 125us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.139984
last_received_ts = 370.139221
last_seq = 3770
current_ts = 370.156647
current_received_ts = 370.155975
current_seq = 3771
count = 76
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 105us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.156647
last_received_ts = 370.155975
last_seq = 3771
current_ts = 370.173309
current_received_ts = 370.172668
current_seq = 3772
count = 77
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 84us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.173309
last_received_ts = 370.172668
last_seq = 3772
current_ts = 370.189972
current_received_ts = 370.189240
current_seq = 3773
count = 78
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 88us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.189972
last_received_ts = 370.189240
last_seq = 3773
current_ts = 370.206635
current_received_ts = 370.205902
current_seq = 3774
count = 79
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 121us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.206635
last_received_ts = 370.205902
last_seq = 3774
current_ts = 370.223297
current_received_ts = 370.222534
current_seq = 3775
count = 80
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 62us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.223297
last_received_ts = 370.222534
last_seq = 3775
current_ts = 370.239960
current_received_ts = 370.239197
current_seq = 3776
count = 81
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 56us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.239960
last_received_ts = 370.239197
last_seq = 3776
current_ts = 370.256622
current_received_ts = 370.255981
current_seq = 3777
count = 82
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 142us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.256622
last_received_ts = 370.255981
last_seq = 3777
current_ts = 370.273315
current_received_ts = 370.272614
current_seq = 3778
count = 83
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 92us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.273315
last_received_ts = 370.272614
last_seq = 3778
current_ts = 370.289978
current_received_ts = 370.289368
current_seq = 3779
count = 84
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 91us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.289978
last_received_ts = 370.289368
last_seq = 3779
current_ts = 370.306641
current_received_ts = 370.305969
current_seq = 3780
count = 85
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 102us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.306641
last_received_ts = 370.305969
last_seq = 3780
current_ts = 370.323303
current_received_ts = 370.322601
current_seq = 3781
count = 86
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 113us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.323303
last_received_ts = 370.322601
last_seq = 3781
current_ts = 370.339966
current_received_ts = 370.339203
current_seq = 3782
count = 87
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 56us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.339966
last_received_ts = 370.339203
last_seq = 3782
current_ts = 370.356628
current_received_ts = 370.355988
current_seq = 3783
count = 88
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 92us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.356628
last_received_ts = 370.355988
last_seq = 3783
current_ts = 370.373291
current_received_ts = 370.372620
current_seq = 3784
count = 89
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 101us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.373291
last_received_ts = 370.372620
last_seq = 3784
current_ts = 370.389954
current_received_ts = 370.389496
current_seq = 3785
count = 90
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 100us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.389954
last_received_ts = 370.389496
last_seq = 3785
current_ts = 370.406616
current_received_ts = 370.405914
current_seq = 3786
count = 91
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 61us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.406616
last_received_ts = 370.405914
last_seq = 3786
current_ts = 370.423279
current_received_ts = 370.422791
current_seq = 3787
count = 92
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 35us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.423279
last_received_ts = 370.422791
last_seq = 3787
current_ts = 370.439941
current_received_ts = 370.439514
current_seq = 3788
count = 93
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 36us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.439941
last_received_ts = 370.439514
last_seq = 3788
current_ts = 370.456604
current_received_ts = 370.455902
current_seq = 3789
count = 94
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 62us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.456604
last_received_ts = 370.455902
last_seq = 3789
current_ts = 370.473267
current_received_ts = 370.472717
current_seq = 3790
count = 95
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 91us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.473267
last_received_ts = 370.472717
last_seq = 3790
current_ts = 370.489929
current_received_ts = 370.489258
current_seq = 3791
count = 96
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 91us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.489929
last_received_ts = 370.489258
last_seq = 3791
current_ts = 370.506592
current_received_ts = 370.506073
current_seq = 3792
count = 97
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 79us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.506592
last_received_ts = 370.506073
last_seq = 3792
current_ts = 370.523285
current_received_ts = 370.522614
current_seq = 3793
count = 98
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 85us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.523285
last_received_ts = 370.522614
last_seq = 3793
current_ts = 370.539948
current_received_ts = 370.539215
current_seq = 3794
count = 99
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 113us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.539948
last_received_ts = 370.539215
last_seq = 3794
current_ts = 370.556610
current_received_ts = 370.556244
current_seq = 3795
count = 100
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 73us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.556610
last_received_ts = 370.556244
last_seq = 3795
current_ts = 370.573273
current_received_ts = 370.572845
current_seq = 3796
count = 101
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 81us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.573273
last_received_ts = 370.572845
last_seq = 3796
current_ts = 370.589935
current_received_ts = 370.589294
current_seq = 3797
count = 102
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 90us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.589935
last_received_ts = 370.589294
last_seq = 3797
current_ts = 370.606598
current_received_ts = 370.605927
current_seq = 3798
count = 103
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 124us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.606598
last_received_ts = 370.605927
last_seq = 3798
current_ts = 370.623260
current_received_ts = 370.622772
current_seq = 3799
count = 104
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 43us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.623260
last_received_ts = 370.622772
last_seq = 3799
current_ts = 370.639923
current_received_ts = 370.639221
current_seq = 3800
count = 105
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 62us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.639923
last_received_ts = 370.639221
last_seq = 3800
current_ts = 370.656586
current_received_ts = 370.655975
current_seq = 3801
count = 106
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 97us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.656586
last_received_ts = 370.655975
last_seq = 3801
current_ts = 370.673248
current_received_ts = 370.672607
current_seq = 3802
count = 107
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 89us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.673248
last_received_ts = 370.672607
last_seq = 3802
current_ts = 370.689911
current_received_ts = 370.689209
current_seq = 3803
count = 108
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 114us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.689911
last_received_ts = 370.689209
last_seq = 3803
current_ts = 370.706573
current_received_ts = 370.705994
current_seq = 3804
count = 109
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 93us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.706573
last_received_ts = 370.705994
last_seq = 3804
current_ts = 370.723236
current_received_ts = 370.722595
current_seq = 3805
count = 110
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 102us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.723236
last_received_ts = 370.722595
last_seq = 3805
current_ts = 370.739899
current_received_ts = 370.739197
current_seq = 3806
count = 111
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 106us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.739899
last_received_ts = 370.739197
last_seq = 3806
current_ts = 370.756561
current_received_ts = 370.755981
current_seq = 3807
count = 112
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 131us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.756561
last_received_ts = 370.755981
last_seq = 3807
current_ts = 370.773254
current_received_ts = 370.772858
current_seq = 3808
count = 113
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 100us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.773254
last_received_ts = 370.772858
last_seq = 3808
current_ts = 370.789917
current_received_ts = 370.789185
current_seq = 3809
count = 114
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 109us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.789917
last_received_ts = 370.789185
last_seq = 3809
current_ts = 370.806580
current_received_ts = 370.805939
current_seq = 3810
count = 115
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 111us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.806580
last_received_ts = 370.805939
last_seq = 3810
current_ts = 370.823242
current_received_ts = 370.822693
current_seq = 3811
count = 116
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 83us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.823242
last_received_ts = 370.822693
last_seq = 3811
current_ts = 370.839905
current_received_ts = 370.839478
current_seq = 3812
count = 117
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 92us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.839905
last_received_ts = 370.839478
last_seq = 3812
current_ts = 370.856567
current_received_ts = 370.855865
current_seq = 3813
count = 118
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 65us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.856567
last_received_ts = 370.855865
last_seq = 3813
current_ts = 370.873230
current_received_ts = 370.872498
current_seq = 3814
count = 119
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 51us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.873230
last_received_ts = 370.872498
last_seq = 3814
current_ts = 370.889893
current_received_ts = 370.889160
current_seq = 3815
count = 120
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 60us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.889893
last_received_ts = 370.889160
last_seq = 3815
current_ts = 370.906555
current_received_ts = 370.905945
current_seq = 3816
count = 121
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 132us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.906555
last_received_ts = 370.905945
last_seq = 3816
current_ts = 370.923218
current_received_ts = 370.922546
current_seq = 3817
count = 122
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 107us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.923218
last_received_ts = 370.922546
last_seq = 3817
current_ts = 370.939880
current_received_ts = 370.939209
current_seq = 3818
count = 123
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 119us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.939880
last_received_ts = 370.939209
last_seq = 3818
current_ts = 370.956543
current_received_ts = 370.956238
current_seq = 3819
count = 124
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 80us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.956543
last_received_ts = 370.956238
last_seq = 3819
current_ts = 370.973236
current_received_ts = 370.972900
current_seq = 3820
count = 125
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 112us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.973236
last_received_ts = 370.972900
last_seq = 3820
current_ts = 370.989899
current_received_ts = 370.989227
current_seq = 3821
count = 126
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 88us
(kms_flip:6415) DEBUG: name = flip
last_ts = 370.989899
last_received_ts = 370.989227
last_seq = 3821
current_ts = 371.006531
current_received_ts = 371.005798
current_seq = 3822
count = 127
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 115us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.006531
last_received_ts = 371.005798
last_seq = 3822
current_ts = 371.023224
current_received_ts = 371.022583
current_seq = 3823
count = 128
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 78us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.023224
last_received_ts = 371.022583
last_seq = 3823
current_ts = 371.039886
current_received_ts = 371.039215
current_seq = 3824
count = 129
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 80us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.039886
last_received_ts = 371.039215
last_seq = 3824
current_ts = 371.056549
current_received_ts = 371.055878
current_seq = 3825
count = 130
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 78us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.056549
last_received_ts = 371.055878
last_seq = 3825
current_ts = 371.073212
current_received_ts = 371.072540
current_seq = 3826
count = 131
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 96us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.073212
last_received_ts = 371.072540
last_seq = 3826
current_ts = 371.089874
current_received_ts = 371.089172
current_seq = 3827
count = 132
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 107us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.089874
last_received_ts = 371.089172
last_seq = 3827
current_ts = 371.106537
current_received_ts = 371.105957
current_seq = 3828
count = 133
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 130us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.106537
last_received_ts = 371.105957
last_seq = 3828
current_ts = 371.123199
current_received_ts = 371.122559
current_seq = 3829
count = 134
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 116us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.123199
last_received_ts = 371.122559
last_seq = 3829
current_ts = 371.139862
current_received_ts = 371.139191
current_seq = 3830
count = 135
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 101us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.139862
last_received_ts = 371.139191
last_seq = 3830
current_ts = 371.156525
current_received_ts = 371.155945
current_seq = 3831
count = 136
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 113us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.156525
last_received_ts = 371.155945
last_seq = 3831
current_ts = 371.173187
current_received_ts = 371.172546
current_seq = 3832
count = 137
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 96us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.173187
last_received_ts = 371.172546
last_seq = 3832
current_ts = 371.189850
current_received_ts = 371.189148
current_seq = 3833
count = 138
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 62us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.189850
last_received_ts = 371.189148
last_seq = 3833
current_ts = 371.206512
current_received_ts = 371.205811
current_seq = 3834
count = 139
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 64us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.206512
last_received_ts = 371.205811
last_seq = 3834
current_ts = 371.223175
current_received_ts = 371.222534
current_seq = 3835
count = 140
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 92us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.223175
last_received_ts = 371.222534
last_seq = 3835
current_ts = 371.239838
current_received_ts = 371.239288
current_seq = 3836
count = 141
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 80us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.239838
last_received_ts = 371.239288
last_seq = 3836
current_ts = 371.256531
current_received_ts = 371.255859
current_seq = 3837
count = 142
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 88us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.256531
last_received_ts = 371.255859
last_seq = 3837
current_ts = 371.273193
current_received_ts = 371.272491
current_seq = 3838
count = 143
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 63us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.273193
last_received_ts = 371.272491
last_seq = 3838
current_ts = 371.289856
current_received_ts = 371.289154
current_seq = 3839
count = 144
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 61us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.289856
last_received_ts = 371.289154
last_seq = 3839
current_ts = 371.306519
current_received_ts = 371.305878
current_seq = 3840
count = 145
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 81us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.306519
last_received_ts = 371.305878
last_seq = 3840
current_ts = 371.323181
current_received_ts = 371.322510
current_seq = 3841
count = 146
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 85us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.323181
last_received_ts = 371.322510
last_seq = 3841
current_ts = 371.339844
current_received_ts = 371.339081
current_seq = 3842
count = 147
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 63us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.339844
last_received_ts = 371.339081
last_seq = 3842
current_ts = 371.356506
current_received_ts = 371.356140
current_seq = 3843
count = 148
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 92us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.356506
last_received_ts = 371.356140
last_seq = 3843
current_ts = 371.373169
current_received_ts = 371.372864
current_seq = 3844
count = 149
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 100us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.373169
last_received_ts = 371.372864
last_seq = 3844
current_ts = 371.389832
current_received_ts = 371.389282
current_seq = 3845
count = 150
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 135us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.389832
last_received_ts = 371.389282
last_seq = 3845
current_ts = 371.406494
current_received_ts = 371.405914
current_seq = 3846
count = 151
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 109us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.406494
last_received_ts = 371.405914
last_seq = 3846
current_ts = 371.423157
current_received_ts = 371.422516
current_seq = 3847
count = 152
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 92us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.423157
last_received_ts = 371.422516
last_seq = 3847
current_ts = 371.439819
current_received_ts = 371.439209
current_seq = 3848
count = 153
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 88us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.439819
last_received_ts = 371.439209
last_seq = 3848
current_ts = 371.456482
current_received_ts = 371.455872
current_seq = 3849
count = 154
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 98us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.456482
last_received_ts = 371.455872
last_seq = 3849
current_ts = 371.473145
current_received_ts = 371.472534
current_seq = 3850
count = 155
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 87us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.473145
last_received_ts = 371.472534
last_seq = 3850
current_ts = 371.489807
current_received_ts = 371.489197
current_seq = 3851
count = 156
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 100us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.489807
last_received_ts = 371.489197
last_seq = 3851
current_ts = 371.506470
current_received_ts = 371.505859
current_seq = 3852
count = 157
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 100us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.506470
last_received_ts = 371.505859
last_seq = 3852
current_ts = 371.523132
current_received_ts = 371.522522
current_seq = 3853
count = 158
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 99us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.523132
last_received_ts = 371.522522
last_seq = 3853
current_ts = 371.539825
current_received_ts = 371.539185
current_seq = 3854
count = 159
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 95us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.539825
last_received_ts = 371.539185
last_seq = 3854
current_ts = 371.556488
current_received_ts = 371.555847
current_seq = 3855
count = 160
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 85us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.556488
last_received_ts = 371.555847
last_seq = 3855
current_ts = 371.573151
current_received_ts = 371.572510
current_seq = 3856
count = 161
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 90us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.573151
last_received_ts = 371.572510
last_seq = 3856
current_ts = 371.589813
current_received_ts = 371.589172
current_seq = 3857
count = 162
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 100us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.589813
last_received_ts = 371.589172
last_seq = 3857
current_ts = 371.606476
current_received_ts = 371.605835
current_seq = 3858
count = 163
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 86us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.606476
last_received_ts = 371.605835
last_seq = 3858
current_ts = 371.623138
current_received_ts = 371.622498
current_seq = 3859
count = 164
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 99us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.623138
last_received_ts = 371.622498
last_seq = 3859
current_ts = 371.639801
current_received_ts = 371.639160
current_seq = 3860
count = 165
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 99us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.639801
last_received_ts = 371.639160
last_seq = 3860
current_ts = 371.656464
current_received_ts = 371.655945
current_seq = 3861
count = 166
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 114us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.656464
last_received_ts = 371.655945
last_seq = 3861
current_ts = 371.673126
current_received_ts = 371.672577
current_seq = 3862
count = 167
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 99us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.673126
last_received_ts = 371.672577
last_seq = 3862
current_ts = 371.689789
current_received_ts = 371.689209
current_seq = 3863
count = 168
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 99us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.689789
last_received_ts = 371.689209
last_seq = 3863
current_ts = 371.706451
current_received_ts = 371.705902
current_seq = 3864
count = 169
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 120us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.706451
last_received_ts = 371.705902
last_seq = 3864
current_ts = 371.723114
current_received_ts = 371.722595
current_seq = 3865
count = 170
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 87us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.723114
last_received_ts = 371.722595
last_seq = 3865
current_ts = 371.739777
current_received_ts = 371.739227
current_seq = 3866
count = 171
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 86us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.739777
last_received_ts = 371.739227
last_seq = 3866
current_ts = 371.756470
current_received_ts = 371.755890
current_seq = 3867
count = 172
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 127us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.756470
last_received_ts = 371.755890
last_seq = 3867
current_ts = 371.773102
current_received_ts = 371.772583
current_seq = 3868
count = 173
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 87us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.773102
last_received_ts = 371.772583
last_seq = 3868
current_ts = 371.789795
current_received_ts = 371.789215
current_seq = 3869
count = 174
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 87us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.789795
last_received_ts = 371.789215
last_seq = 3869
current_ts = 371.806458
current_received_ts = 371.805908
current_seq = 3870
count = 175
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 129us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.806458
last_received_ts = 371.805908
last_seq = 3870
current_ts = 371.823120
current_received_ts = 371.822571
current_seq = 3871
count = 176
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 87us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.823120
last_received_ts = 371.822571
last_seq = 3871
current_ts = 371.839783
current_received_ts = 371.839203
current_seq = 3872
count = 177
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 100us
(kms_flip:6415) DEBUG: name = flip
last_ts = 371.839783
last_received_ts = 371.839203
last_seq = 3872
current_ts = 371.856445
current_received_ts = 371.855865
current_seq = 3873
count = 178
seq_step = 1
(kms_flip:6415) DEBUG: Vblank took 514us
(kms_flip:6415) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:930:
(kms_flip:6415) CRITICAL: Failed assertion: end - start < 500
(kms_flip:6415) igt_core-INFO: Stack trace:
(kms_flip:6415) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:6415) igt_core-INFO:   #1 ../tests/kms_flip.c:925 run_test_on_crtc_set.constprop.0()
(kms_flip:6415) igt_core-INFO:   #2 ../tests/kms_flip.c:1891 run_test()
(kms_flip:6415) igt_core-INFO:   #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047()
(kms_flip:6415) igt_core-INFO:   #4 ../tests/kms_flip.c:2047 main()
(kms_flip:6415) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:6415) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:6415) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (4.361s)

Dmesg

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [367.724716] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [367.727186] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [367.727191] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa

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

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

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

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

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

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

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

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

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

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

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

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

<7> [367.738177] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432]

<7> [367.810005] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [367.817064] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0

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

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

<7> [367.817262] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [367.817328] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [367.817389] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [368.100208] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)

<7> [368.100692] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

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

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

<7> [368.102691] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]

<7> [368.103040] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]

<7> [368.103301] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

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

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

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

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

<7> [368.104704] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [368.111541] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051

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

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

<7> [368.111782] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0

<7> [368.111852] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197

<7> [368.111930] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [368.115427] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97

<7> [368.115519] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906

<7> [368.115603] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0

<7> [368.115680] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [368.115782] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [368.115885] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa

<7> [368.115986] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa

<7> [368.116085] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa

<7> [368.116174] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855

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

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

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

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

<7> [368.116603] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no

<7> [368.116701] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [368.119913] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)

<7> [368.120049] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [368.826995] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80

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

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

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

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

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

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

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

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

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

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

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

<7> [368.837841] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 192000

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

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

<7> [368.856357] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

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

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

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

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

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

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

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