igt@kms_flip@flip-vs-expired-vblank-interruptible@a-hdmi-a2 on shard-glk@IGT

Detail	Value
Duration	5.32 seconds
Hostname	shard-glk5
Igt-Version	IGT-Version: 2.3-gd9d59d09a (x86_64) (Linux: 6.19.0-rc8-CI_DRM_17930-g241994730989+ x86_64)
Out	Starting dynamic subtest: A-HDMI-A2 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1889 run_test() #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045() #4 ../tests/kms_flip.c:2045 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A2: FAIL (5.319s)
Err	Starting dynamic subtest: A-HDMI-A2 (kms_flip:2546) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2546) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2546) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-HDMI-A2 failed. ** DEBUG (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 741.436340 last_received_ts = 741.436523 last_seq = 30849 current_ts = 741.453003 current_received_ts = 741.452515 current_seq = 30850 count = 162 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 741.453003 last_received_ts = 741.452515 last_seq = 30850 current_ts = 741.469666 current_received_ts = 741.469482 current_seq = 30851 count = 163 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.469666 last_received_ts = 741.469482 last_seq = 30851 current_ts = 741.486328 current_received_ts = 741.486206 current_seq = 30852 count = 164 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 25us (kms_flip:2546) DEBUG: name = flip last_ts = 741.486328 last_received_ts = 741.486206 last_seq = 30852 current_ts = 741.502991 current_received_ts = 741.502502 current_seq = 30853 count = 165 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.502991 last_received_ts = 741.502502 last_seq = 30853 current_ts = 741.519653 current_received_ts = 741.519958 current_seq = 30854 count = 166 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 741.519653 last_received_ts = 741.519958 last_seq = 30854 current_ts = 741.536316 current_received_ts = 741.536133 current_seq = 30855 count = 167 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 741.536316 last_received_ts = 741.536133 last_seq = 30855 current_ts = 741.553040 current_received_ts = 741.552551 current_seq = 30856 count = 168 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.553040 last_received_ts = 741.552551 last_seq = 30856 current_ts = 741.569702 current_received_ts = 741.569458 current_seq = 30857 count = 169 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.569702 last_received_ts = 741.569458 last_seq = 30857 current_ts = 741.586365 current_received_ts = 741.585815 current_seq = 30858 count = 170 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 741.586365 last_received_ts = 741.585815 last_seq = 30858 current_ts = 741.603027 current_received_ts = 741.602600 current_seq = 30859 count = 171 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.603027 last_received_ts = 741.602600 last_seq = 30859 current_ts = 741.619690 current_received_ts = 741.619446 current_seq = 30860 count = 172 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 741.619690 last_received_ts = 741.619446 last_seq = 30860 current_ts = 741.636353 current_received_ts = 741.636169 current_seq = 30861 count = 173 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 25us (kms_flip:2546) DEBUG: name = flip last_ts = 741.636353 last_received_ts = 741.636169 last_seq = 30861 current_ts = 741.653015 current_received_ts = 741.652527 current_seq = 30862 count = 174 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 741.653015 last_received_ts = 741.652527 last_seq = 30862 current_ts = 741.669678 current_received_ts = 741.669739 current_seq = 30863 count = 175 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.669678 last_received_ts = 741.669739 last_seq = 30863 current_ts = 741.686401 current_received_ts = 741.686279 current_seq = 30864 count = 176 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.686401 last_received_ts = 741.686279 last_seq = 30864 current_ts = 741.703064 current_received_ts = 741.702637 current_seq = 30865 count = 177 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 741.703064 last_received_ts = 741.702637 last_seq = 30865 current_ts = 741.719727 current_received_ts = 741.719849 current_seq = 30866 count = 178 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 741.719727 last_received_ts = 741.719849 last_seq = 30866 current_ts = 741.736389 current_received_ts = 741.735901 current_seq = 30867 count = 179 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 19us (kms_flip:2546) DEBUG: name = flip last_ts = 741.736389 last_received_ts = 741.735901 last_seq = 30867 current_ts = 741.753052 current_received_ts = 741.752625 current_seq = 30868 count = 180 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.753052 last_received_ts = 741.752625 last_seq = 30868 current_ts = 741.769714 current_received_ts = 741.769470 current_seq = 30869 count = 181 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.769714 last_received_ts = 741.769470 last_seq = 30869 current_ts = 741.786377 current_received_ts = 741.786255 current_seq = 30870 count = 182 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 25us (kms_flip:2546) DEBUG: name = flip last_ts = 741.786377 last_received_ts = 741.786255 last_seq = 30870 current_ts = 741.803040 current_received_ts = 741.802612 current_seq = 30871 count = 183 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.803040 last_received_ts = 741.802612 last_seq = 30871 current_ts = 741.819702 current_received_ts = 741.819946 current_seq = 30872 count = 184 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 59us (kms_flip:2546) DEBUG: name = flip last_ts = 741.819702 last_received_ts = 741.819946 last_seq = 30872 current_ts = 741.836365 current_received_ts = 741.836304 current_seq = 30873 count = 185 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 741.836365 last_received_ts = 741.836304 last_seq = 30873 current_ts = 741.853088 current_received_ts = 741.853088 current_seq = 30874 count = 186 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.853088 last_received_ts = 741.853088 last_seq = 30874 current_ts = 741.869751 current_received_ts = 741.869873 current_seq = 30875 count = 187 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 741.869751 last_received_ts = 741.869873 last_seq = 30875 current_ts = 741.886414 current_received_ts = 741.885925 current_seq = 30876 count = 188 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 65us (kms_flip:2546) DEBUG: name = flip last_ts = 741.886414 last_received_ts = 741.885925 last_seq = 30876 current_ts = 741.903076 current_received_ts = 741.902771 current_seq = 30877 count = 189 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 741.903076 last_received_ts = 741.902771 last_seq = 30877 current_ts = 741.919739 current_received_ts = 741.919495 current_seq = 30878 count = 190 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 741.919739 last_received_ts = 741.919495 last_seq = 30878 current_ts = 741.936401 current_received_ts = 741.935974 current_seq = 30879 count = 191 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 741.936401 last_received_ts = 741.935974 last_seq = 30879 current_ts = 741.953064 current_received_ts = 741.953125 current_seq = 30880 count = 192 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 741.953064 last_received_ts = 741.953125 last_seq = 30880 current_ts = 741.969788 current_received_ts = 741.969910 current_seq = 30881 count = 193 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 741.969788 last_received_ts = 741.969910 last_seq = 30881 current_ts = 741.986450 current_received_ts = 741.986267 current_seq = 30882 count = 194 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 741.986450 last_received_ts = 741.986267 last_seq = 30882 current_ts = 742.003113 current_received_ts = 742.002625 current_seq = 30883 count = 195 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.003113 last_received_ts = 742.002625 last_seq = 30883 current_ts = 742.019775 current_received_ts = 742.019836 current_seq = 30884 count = 196 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.019775 last_received_ts = 742.019836 last_seq = 30884 current_ts = 742.036438 current_received_ts = 742.035950 current_seq = 30885 count = 197 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 60us (kms_flip:2546) DEBUG: name = flip last_ts = 742.036438 last_received_ts = 742.035950 last_seq = 30885 current_ts = 742.053101 current_received_ts = 742.052795 current_seq = 30886 count = 198 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 742.053101 last_received_ts = 742.052795 last_seq = 30886 current_ts = 742.069763 current_received_ts = 742.069824 current_seq = 30887 count = 199 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.069763 last_received_ts = 742.069824 last_seq = 30887 current_ts = 742.086426 current_received_ts = 742.086243 current_seq = 30888 count = 200 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.086426 last_received_ts = 742.086243 last_seq = 30888 current_ts = 742.103088 current_received_ts = 742.102661 current_seq = 30889 count = 201 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.103088 last_received_ts = 742.102661 last_seq = 30889 current_ts = 742.119751 current_received_ts = 742.119934 current_seq = 30890 count = 202 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 742.119751 last_received_ts = 742.119934 last_seq = 30890 current_ts = 742.136475 current_received_ts = 742.136353 current_seq = 30891 count = 203 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 742.136475 last_received_ts = 742.136353 last_seq = 30891 current_ts = 742.153137 current_received_ts = 742.152649 current_seq = 30892 count = 204 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.153137 last_received_ts = 742.152649 last_seq = 30892 current_ts = 742.169800 current_received_ts = 742.169861 current_seq = 30893 count = 205 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.169800 last_received_ts = 742.169861 last_seq = 30893 current_ts = 742.186462 current_received_ts = 742.186096 current_seq = 30894 count = 206 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 742.186462 last_received_ts = 742.186096 last_seq = 30894 current_ts = 742.203125 current_received_ts = 742.203003 current_seq = 30895 count = 207 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.203125 last_received_ts = 742.203003 last_seq = 30895 current_ts = 742.219788 current_received_ts = 742.219482 current_seq = 30896 count = 208 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 25us (kms_flip:2546) DEBUG: name = flip last_ts = 742.219788 last_received_ts = 742.219482 last_seq = 30896 current_ts = 742.236450 current_received_ts = 742.236267 current_seq = 30897 count = 209 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.236450 last_received_ts = 742.236267 last_seq = 30897 current_ts = 742.253174 current_received_ts = 742.252686 current_seq = 30898 count = 210 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.253174 last_received_ts = 742.252686 last_seq = 30898 current_ts = 742.269836 current_received_ts = 742.269531 current_seq = 30899 count = 211 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.269836 last_received_ts = 742.269531 last_seq = 30899 current_ts = 742.286499 current_received_ts = 742.286621 current_seq = 30900 count = 212 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 742.286499 last_received_ts = 742.286621 last_seq = 30900 current_ts = 742.303162 current_received_ts = 742.302673 current_seq = 30901 count = 213 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 25us (kms_flip:2546) DEBUG: name = flip last_ts = 742.303162 last_received_ts = 742.302673 last_seq = 30901 current_ts = 742.319824 current_received_ts = 742.319458 current_seq = 30902 count = 214 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.319824 last_received_ts = 742.319458 last_seq = 30902 current_ts = 742.336487 current_received_ts = 742.336243 current_seq = 30903 count = 215 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.336487 last_received_ts = 742.336243 last_seq = 30903 current_ts = 742.353149 current_received_ts = 742.352722 current_seq = 30904 count = 216 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.353149 last_received_ts = 742.352722 last_seq = 30904 current_ts = 742.369812 current_received_ts = 742.369446 current_seq = 30905 count = 217 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.369812 last_received_ts = 742.369446 last_seq = 30905 current_ts = 742.386475 current_received_ts = 742.386658 current_seq = 30906 count = 218 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 19us (kms_flip:2546) DEBUG: name = flip last_ts = 742.386475 last_received_ts = 742.386658 last_seq = 30906 current_ts = 742.403137 current_received_ts = 742.403564 current_seq = 30907 count = 219 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 742.403137 last_received_ts = 742.403564 last_seq = 30907 current_ts = 742.419861 current_received_ts = 742.419861 current_seq = 30908 count = 220 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.419861 last_received_ts = 742.419861 last_seq = 30908 current_ts = 742.436523 current_received_ts = 742.436279 current_seq = 30909 count = 221 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.436523 last_received_ts = 742.436279 last_seq = 30909 current_ts = 742.453186 current_received_ts = 742.452942 current_seq = 30910 count = 222 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.453186 last_received_ts = 742.452942 last_seq = 30910 current_ts = 742.469849 current_received_ts = 742.469482 current_seq = 30911 count = 223 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.469849 last_received_ts = 742.469482 last_seq = 30911 current_ts = 742.486511 current_received_ts = 742.486755 current_seq = 30912 count = 224 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.486511 last_received_ts = 742.486755 last_seq = 30912 current_ts = 742.503174 current_received_ts = 742.502686 current_seq = 30913 count = 225 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.503174 last_received_ts = 742.502686 last_seq = 30913 current_ts = 742.519836 current_received_ts = 742.519531 current_seq = 30914 count = 226 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.519836 last_received_ts = 742.519531 last_seq = 30914 current_ts = 742.536499 current_received_ts = 742.536743 current_seq = 30915 count = 227 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.536499 last_received_ts = 742.536743 last_seq = 30915 current_ts = 742.553223 current_received_ts = 742.553040 current_seq = 30916 count = 228 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.553223 last_received_ts = 742.553040 last_seq = 30916 current_ts = 742.569885 current_received_ts = 742.569580 current_seq = 30917 count = 229 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 742.569885 last_received_ts = 742.569580 last_seq = 30917 current_ts = 742.586548 current_received_ts = 742.586121 current_seq = 30918 count = 230 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 742.586548 last_received_ts = 742.586121 last_seq = 30918 current_ts = 742.603210 current_received_ts = 742.602783 current_seq = 30919 count = 231 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.603210 last_received_ts = 742.602783 last_seq = 30919 current_ts = 742.619873 current_received_ts = 742.620056 current_seq = 30920 count = 232 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 35us (kms_flip:2546) DEBUG: name = flip last_ts = 742.619873 last_received_ts = 742.620056 last_seq = 30920 current_ts = 742.636536 current_received_ts = 742.636353 current_seq = 30921 count = 233 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.636536 last_received_ts = 742.636353 last_seq = 30921 current_ts = 742.653198 current_received_ts = 742.652832 current_seq = 30922 count = 234 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.653198 last_received_ts = 742.652832 last_seq = 30922 current_ts = 742.669922 current_received_ts = 742.669495 current_seq = 30923 count = 235 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.669922 last_received_ts = 742.669495 last_seq = 30923 current_ts = 742.686584 current_received_ts = 742.686707 current_seq = 30924 count = 236 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 742.686584 last_received_ts = 742.686707 last_seq = 30924 current_ts = 742.703247 current_received_ts = 742.703491 current_seq = 30925 count = 237 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 742.703247 last_received_ts = 742.703491 last_seq = 30925 current_ts = 742.719910 current_received_ts = 742.719849 current_seq = 30926 count = 238 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.719910 last_received_ts = 742.719849 last_seq = 30926 current_ts = 742.736572 current_received_ts = 742.736389 current_seq = 30927 count = 239 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.736572 last_received_ts = 742.736389 last_seq = 30927 current_ts = 742.753235 current_received_ts = 742.752991 current_seq = 30928 count = 240 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 742.753235 last_received_ts = 742.752991 last_seq = 30928 current_ts = 742.769897 current_received_ts = 742.769409 current_seq = 30929 count = 241 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.769897 last_received_ts = 742.769409 last_seq = 30929 current_ts = 742.786560 current_received_ts = 742.786621 current_seq = 30930 count = 242 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 742.786560 last_received_ts = 742.786621 last_seq = 30930 current_ts = 742.803223 current_received_ts = 742.803162 current_seq = 30931 count = 243 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 742.803223 last_received_ts = 742.803162 last_seq = 30931 current_ts = 742.819885 current_received_ts = 742.819458 current_seq = 30932 count = 244 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.819885 last_received_ts = 742.819458 last_seq = 30932 current_ts = 742.836609 current_received_ts = 742.836426 current_seq = 30933 count = 245 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 25us (kms_flip:2546) DEBUG: name = flip last_ts = 742.836609 last_received_ts = 742.836426 last_seq = 30933 current_ts = 742.853271 current_received_ts = 742.853088 current_seq = 30934 count = 246 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 25us (kms_flip:2546) DEBUG: name = flip last_ts = 742.853271 last_received_ts = 742.853088 last_seq = 30934 current_ts = 742.869934 current_received_ts = 742.869446 current_seq = 30935 count = 247 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 742.869934 last_received_ts = 742.869446 last_seq = 30935 current_ts = 742.886597 current_received_ts = 742.886475 current_seq = 30936 count = 248 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 742.886597 last_received_ts = 742.886475 last_seq = 30936 current_ts = 742.903259 current_received_ts = 742.903076 current_seq = 30937 count = 249 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 742.903259 last_received_ts = 742.903076 last_seq = 30937 current_ts = 742.919922 current_received_ts = 742.919861 current_seq = 30938 count = 250 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.919922 last_received_ts = 742.919861 last_seq = 30938 current_ts = 742.936584 current_received_ts = 742.936401 current_seq = 30939 count = 251 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 742.936584 last_received_ts = 742.936401 last_seq = 30939 current_ts = 742.953308 current_received_ts = 742.953552 current_seq = 30940 count = 252 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 19us (kms_flip:2546) DEBUG: name = flip last_ts = 742.953308 last_received_ts = 742.953552 last_seq = 30940 current_ts = 742.969971 current_received_ts = 742.969543 current_seq = 30941 count = 253 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.969971 last_received_ts = 742.969543 last_seq = 30941 current_ts = 742.986633 current_received_ts = 742.986450 current_seq = 30942 count = 254 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 742.986633 last_received_ts = 742.986450 last_seq = 30942 current_ts = 743.003296 current_received_ts = 743.003113 current_seq = 30943 count = 255 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.003296 last_received_ts = 743.003113 last_seq = 30943 current_ts = 743.019958 current_received_ts = 743.019531 current_seq = 30944 count = 256 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.019958 last_received_ts = 743.019531 last_seq = 30944 current_ts = 743.036621 current_received_ts = 743.036438 current_seq = 30945 count = 257 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.036621 last_received_ts = 743.036438 last_seq = 30945 current_ts = 743.053284 current_received_ts = 743.052795 current_seq = 30946 count = 258 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 743.053284 last_received_ts = 743.052795 last_seq = 30946 current_ts = 743.069946 current_received_ts = 743.070007 current_seq = 30947 count = 259 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 743.069946 last_received_ts = 743.070007 last_seq = 30947 current_ts = 743.086609 current_received_ts = 743.086426 current_seq = 30948 count = 260 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.086609 last_received_ts = 743.086426 last_seq = 30948 current_ts = 743.103271 current_received_ts = 743.103088 current_seq = 30949 count = 261 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 743.103271 last_received_ts = 743.103088 last_seq = 30949 current_ts = 743.119995 current_received_ts = 743.119507 current_seq = 30950 count = 262 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.119995 last_received_ts = 743.119507 last_seq = 30950 current_ts = 743.136658 current_received_ts = 743.136475 current_seq = 30951 count = 263 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.136658 last_received_ts = 743.136475 last_seq = 30951 current_ts = 743.153320 current_received_ts = 743.152771 current_seq = 30952 count = 264 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.153320 last_received_ts = 743.152771 last_seq = 30952 current_ts = 743.169983 current_received_ts = 743.169983 current_seq = 30953 count = 265 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 743.169983 last_received_ts = 743.169983 last_seq = 30953 current_ts = 743.186646 current_received_ts = 743.186401 current_seq = 30954 count = 266 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 743.186646 last_received_ts = 743.186401 last_seq = 30954 current_ts = 743.203308 current_received_ts = 743.203125 current_seq = 30955 count = 267 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.203308 last_received_ts = 743.203125 last_seq = 30955 current_ts = 743.219971 current_received_ts = 743.219543 current_seq = 30956 count = 268 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.219971 last_received_ts = 743.219543 last_seq = 30956 current_ts = 743.236633 current_received_ts = 743.236572 current_seq = 30957 count = 269 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.236633 last_received_ts = 743.236572 last_seq = 30957 current_ts = 743.253357 current_received_ts = 743.253601 current_seq = 30958 count = 270 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 20us (kms_flip:2546) DEBUG: name = flip last_ts = 743.253357 last_received_ts = 743.253601 last_seq = 30958 current_ts = 743.270020 current_received_ts = 743.269531 current_seq = 30959 count = 271 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 743.270020 last_received_ts = 743.269531 last_seq = 30959 current_ts = 743.286682 current_received_ts = 743.286499 current_seq = 30960 count = 272 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 743.286682 last_received_ts = 743.286499 last_seq = 30960 current_ts = 743.303345 current_received_ts = 743.302856 current_seq = 30961 count = 273 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 743.303345 last_received_ts = 743.302856 last_seq = 30961 current_ts = 743.320007 current_received_ts = 743.319641 current_seq = 30962 count = 274 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 25us (kms_flip:2546) DEBUG: name = flip last_ts = 743.320007 last_received_ts = 743.319641 last_seq = 30962 current_ts = 743.336670 current_received_ts = 743.336853 current_seq = 30963 count = 275 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.336670 last_received_ts = 743.336853 last_seq = 30963 current_ts = 743.353333 current_received_ts = 743.353149 current_seq = 30964 count = 276 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 743.353333 last_received_ts = 743.353149 last_seq = 30964 current_ts = 743.369995 current_received_ts = 743.369568 current_seq = 30965 count = 277 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 24us (kms_flip:2546) DEBUG: name = flip last_ts = 743.369995 last_received_ts = 743.369568 last_seq = 30965 current_ts = 743.386719 current_received_ts = 743.386658 current_seq = 30966 count = 278 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 21us (kms_flip:2546) DEBUG: name = flip last_ts = 743.386719 last_received_ts = 743.386658 last_seq = 30966 current_ts = 743.403381 current_received_ts = 743.403198 current_seq = 30967 count = 279 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.403381 last_received_ts = 743.403198 last_seq = 30967 current_ts = 743.420044 current_received_ts = 743.419556 current_seq = 30968 count = 280 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 23us (kms_flip:2546) DEBUG: name = flip last_ts = 743.420044 last_received_ts = 743.419556 last_seq = 30968 current_ts = 743.436707 current_received_ts = 743.436462 current_seq = 30969 count = 281 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 22us (kms_flip:2546) DEBUG: name = flip last_ts = 743.436707 last_received_ts = 743.436462 last_seq = 30969 current_ts = 743.453369 current_received_ts = 743.452881 current_seq = 30970 count = 282 seq_step = 1 (kms_flip:2546) DEBUG: Vblank took 941us (kms_flip:2546) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2546) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2546) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2546) igt_core-INFO: Stack trace: (kms_flip:2546) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2546) igt_core-INFO: #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() (kms_flip:2546) igt_core-INFO: #2 ../tests/kms_flip.c:1889 run_test() (kms_flip:2546) igt_core-INFO: #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045() (kms_flip:2546) igt_core-INFO: #4 ../tests/kms_flip.c:2045 main() (kms_flip:2546) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2546) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2546) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A2: FAIL (5.319s)
Dmesg	<6> [738.320884] [IGT] kms_flip: starting dynamic subtest A-HDMI-A2 <7> [738.322538] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:179] <7> [738.323560] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:182] <7> [738.361929] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:77:pipe A] <7> [738.362433] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:120:pipe B] <7> [738.363080] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:163:pipe C] <7> [738.363257] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.enable (expected yes, found no) <7> [738.363866] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.active (expected yes, found no) <7> [738.364365] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1) <7> [738.364922] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in lane_count (expected 4, found 0) <7> [738.365419] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000) <7> [738.365939] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [738.366434] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [738.366964] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [738.367458] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [738.367980] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [738.368436] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [738.368916] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [738.369373] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [738.369848] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [738.370309] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [738.370778] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0) <7> [738.371235] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0) <7> [738.371712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [738.372171] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [738.372625] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [738.373097] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [738.373556] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [738.374030] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [738.374486] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [738.374953] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [738.375409] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [738.375883] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [738.376339] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0) <7> [738.376807] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0) <7> [738.377265] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [738.377738] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [738.378197] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [738.378654] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [738.379121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [738.379590] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in has_hdmi_sink (expected yes, found no) <7> [738.380070] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in has_infoframe (expected yes, found no) <7> [738.380531] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in pipe_bpp (expected 36, found 0) <7> [738.381015] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [738.381474] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [738.381949] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in port_clock (expected 222750, found 0) <7> [738.382409] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000) <7> [738.382878] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000) <7> [738.383339] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in avi infoframe <7> [738.383816] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [738.384272] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [738.384277] i915 0000:00:02.0: colorspace: RGB <7> [738.384281] i915 0000:00:02.0: scan mode: Underscan <7> [738.384284] i915 0000:00:02.0: colorimetry: No Data <7> [738.384288] i915 0000:00:02.0: picture aspect: No Data <7> [738.384291] i915 0000:00:02.0: active aspect: Same as Picture <7> [738.384295] i915 0000:00:02.0: itc: No Data <7> [738.384298] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [738.384302] i915 0000:00:02.0: quantization range: Full <7> [738.384305] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [738.384309] i915 0000:00:02.0: video code: 0 <7> [738.384312] i915 0000:00:02.0: ycc quantization range: Full <7> [738.384315] i915 0000:00:02.0: hdmi content type: Graphics <7> [738.384319] i915 0000:00:02.0: pixel repeat: 0 <7> [738.384322] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [738.384326] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [738.384793] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in spd infoframe <7> [738.385250] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [738.385722] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [738.385726] i915 0000:00:02.0: vendor: Intel <7> [738.385730] i915 0000:00:02.0: product: Integrated gfx <7> [738.385734] i915 0000:00:02.0: source device information: PC General (0x9) <7> [738.385738] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [738.386205] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hdmi infoframe <7> [738.386660] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [738.387128] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [738.387133] i915 0000:00:02.0: empty frame <7> [738.387136] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [738.387595] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:163:pipe C] fastset requirement not met, forcing full modeset <7> [738.388073] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:163:pipe C] releasing PORT PLL B <7> [738.389548] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:163:pipe C] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x4 -> 0x0 <7> [738.390225] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:157:cursor C] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0 <7> [738.391003] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:163:pipe C] min cdclk: 192000 kHz -> 0 kHz <7> [738.391521] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [738.392013] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz <7> [738.392468] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4 <7> [738.392958] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:163:pipe C] enable: no [modeset] <7> [738.393419] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:121:plane 1C] fb: [NOFB], visible: no <7> [738.393892] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:130:plane 2C] fb: [NOFB], visible: no <7> [738.394350] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:139:plane 3C] fb: [NOFB], visible: no <7> [738.394830] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:148:plane 4C] fb: [NOFB], visible: no <7> [738.395284] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:157:cursor C] fb: [NOFB], visible: no <7> [738.396593] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:165:HDMI-A-1][ENCODER:164:DDI B/PHY B] Disable audio codec on [CRTC:163:pipe C] <7> [738.429434] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port B <7> [738.430430] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe C <7> [738.442249] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10 <7> [738.447733] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time <7> [738.553180] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B <7> [738.554501] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL B (active 0x4, on? 1) for [CRTC:163:pipe C] <7> [738.557787] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL B <7> [738.558409] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 79200 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 4 <7> [738.559010] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B] <7> [738.559508] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:174:DDI C/PHY C] <7> [738.559999] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:165:HDMI-A-1] <7> [738.560807] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-b <7> [738.561419] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:163:pipe C] <7> [738.562416] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:77:pipe A] <7> [738.562508] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [738.563075] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz <7> [738.563560] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13 <7> [738.564394] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 316800 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 13 <7> [738.565823] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:175:HDMI-A-2] <7> [738.566053] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [738.566606] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:77:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [738.567153] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:174:DDI C/PHY C] [CRTC:77:pipe A] <7> [738.567602] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [738.568121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [738.568581] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [738.569063] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [738.569519] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d) <7> [738.570002] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [738.570459] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [738.570942] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [738.571398] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [738.571877] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [738.572333] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [738.572816] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [738.573274] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [738.573748] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [738.574204] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [738.574687] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [738.575142] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [738.575599] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [738.576076] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [738.576532] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [738.577016] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [738.577475] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [738.577954] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [738.578411] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [738.578895] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [738.579354] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [738.579829] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [738.580286] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [738.580774] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [738.581234] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [738.581712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [738.582173] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [738.582628] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [738.583111] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [738.583573] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [738.584051] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in has_infoframe (expected no, found yes) <7> [738.584517] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [738.585003] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [738.585463] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [738.585940] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in port_clock (expected 0, found 222750) <7> [738.586402] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [738.586893] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [738.587350] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in avi infoframe <7> [738.587831] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [738.588288] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [738.588782] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [738.588787] i915 0000:00:02.0: colorspace: RGB <7> [738.588791] i915 0000:00:02.0: scan mode: Underscan <7> [738.588795] i915 0000:00:02.0: colorimetry: No Data <7> [738.588798] i915 0000:00:02.0: picture aspect: No Data <7> [738.588801] i915 0000:00:02.0: active aspect: Same as Picture <7> [738.588805] i915 0000:00:02.0: itc: No Data <7> [738.588808] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [738.588812] i915 0000:00:02.0: quantization range: Full <7> [738.588815] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [738.588819] i915 0000:00:02.0: video code: 0 <7> [738.588822] i915 0000:00:02.0: ycc quantization range: Full <7> [738.588826] i915 0000:00:02.0: hdmi content type: Graphics <7> [738.588829] i915 0000:00:02.0: pixel repeat: 0 <7> [738.588832] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [738.588836] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in spd infoframe <7> [738.589293] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [738.589766] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [738.590223] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [738.590227] i915 0000:00:02.0: vendor: Intel <7> [738.590231] i915 0000:00:02.0: product: Integrated gfx <7> [738.590234] i915 0000:00:02.0: source device information: PC General (0x9) <7> [738.590238] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hdmi infoframe <7> [738.590722] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [738.591176] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [738.591628] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [738.591637] i915 0000:00:02.0: empty frame <7> [738.591662] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:77:pipe A] fastset requirement not met, forcing full modeset <7> [738.592466] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:77:pipe A] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x1 <7> [738.593357] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988 <7> [738.593853] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:71:cursor A] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32 <7> [738.594300] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [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> [738.594768] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0 <7> [738.595215] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0 <7> [738.595690] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0 <7> [738.596385] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:77:pipe A] min cdclk: 0 kHz -> 192000 kHz <7> [738.596930] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:77:pipe A] using pre-allocated PORT PLL C <7> [738.597395] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:77:pipe A] reserving PORT PLL C <7> [738.597894] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:77:pipe A] enable: yes [modeset] <7> [738.598355] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [738.598842] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0 <7> [738.599298] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [738.599787] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [738.600244] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [738.600748] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [738.601204] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [738.601685] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [738.602143] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [738.602147] i915 0000:00:02.0: colorspace: RGB <7> [738.602150] i915 0000:00:02.0: scan mode: Underscan <7> [738.602154] i915 0000:00:02.0: colorimetry: No Data <7> [738.602158] i915 0000:00:02.0: picture aspect: No Data <7> [738.602161] i915 0000:00:02.0: active aspect: Same as Picture <7> [738.602164] i915 0000:00:02.0: itc: No Data <7> [738.602167] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [738.602171] i915 0000:00:02.0: quantization range: Full <7> [738.602174] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [738.602178] i915 0000:00:02.0: video code: 0 <7> [738.602181] i915 0000:00:02.0: ycc quantization range: Full <7> [738.602184] i915 0000:00:02.0: hdmi content type: Graphics <7> [738.602187] i915 0000:00:02.0: pixel repeat: 0 <7> [738.602191] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [738.602195] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [738.602198] i915 0000:00:02.0: vendor: Intel <7> [738.602202] i915 0000:00:02.0: product: Integrated gfx <7> [738.602205] i915 0000:00:02.0: source device information: PC General (0x9) <7> [738.602209] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [738.602213] i915 0000:00:02.0: empty frame <7> [738.602216] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00 <7> [738.602702] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00 <7> [738.603160] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [738.603612] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [738.604091] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0 <7> [738.604548] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0 <7> [738.605028] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [738.605486] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 <7> [738.605961] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 <7> [738.606418] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [738.606904] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [738.607363] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [738.607841] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000 <7> [738.608300] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0 <7> [738.608786] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [738.609243] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [738.609723] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [738.610181] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6200, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d <7> [738.610666] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [738.611122] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [738.611575] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [738.612050] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [738.612504] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [738.612987] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [738.613443] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [738.613920] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [738.614378] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:179] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [738.614866] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [738.615321] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [738.615796] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:44:plane 2A] fb: [NOFB], visible: no <7> [738.616252] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:plane 3A] fb: [NOFB], visible: no <7> [738.616738] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:62:plane 4A] fb: [NOFB], visible: no <7> [738.617197] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:71:cursor A] fb: [NOFB], visible: no <7> [738.617754] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL <7> [738.617770] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled <7> [738.618479] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c <7> [738.619444] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B] <7> [738.619981] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:174:DDI C/PHY C] <7> [738.620607] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x1, on? 0) for [CRTC:77:pipe A] <7> [738.621102] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C <7> [738.621826] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C <7> [738.622387] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [738.623801] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 16588800 bytes of contiguous stolen space for FBC, limit: 1 <7> [738.624261] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A] <7> [738.640723] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:175:HDMI-A-2][ENCODER:174:DDI C/PHY C] Enable audio codec on [CRTC:77:pipe A], 32 bytes ELD <7> [738.657205] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000) <7> [738.657809] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N <7> [738.658508] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:175:HDMI-A-2] <7> [738.660340] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:77:pipe A] <6> [743.645581] [IGT] kms_flip: finished subtest A-HDMI-A2, FAIL

Detail

Value

Duration

5.32 seconds

Hostname

shard-glk5

Igt-Version

IGT-Version: 2.3-gd9d59d09a (x86_64) (Linux: 6.19.0-rc8-CI_DRM_17930-g241994730989+ x86_64)

Out

Starting dynamic subtest: A-HDMI-A2
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1889 run_test()
  #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045()
  #4 ../tests/kms_flip.c:2045 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A2: FAIL (5.319s)

Err

Starting dynamic subtest: A-HDMI-A2
(kms_flip:2546) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2546) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2546) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.436340
last_received_ts = 741.436523
last_seq = 30849
current_ts = 741.453003
current_received_ts = 741.452515
current_seq = 30850
count = 162
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.453003
last_received_ts = 741.452515
last_seq = 30850
current_ts = 741.469666
current_received_ts = 741.469482
current_seq = 30851
count = 163
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.469666
last_received_ts = 741.469482
last_seq = 30851
current_ts = 741.486328
current_received_ts = 741.486206
current_seq = 30852
count = 164
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 25us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.486328
last_received_ts = 741.486206
last_seq = 30852
current_ts = 741.502991
current_received_ts = 741.502502
current_seq = 30853
count = 165
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.502991
last_received_ts = 741.502502
last_seq = 30853
current_ts = 741.519653
current_received_ts = 741.519958
current_seq = 30854
count = 166
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.519653
last_received_ts = 741.519958
last_seq = 30854
current_ts = 741.536316
current_received_ts = 741.536133
current_seq = 30855
count = 167
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.536316
last_received_ts = 741.536133
last_seq = 30855
current_ts = 741.553040
current_received_ts = 741.552551
current_seq = 30856
count = 168
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.553040
last_received_ts = 741.552551
last_seq = 30856
current_ts = 741.569702
current_received_ts = 741.569458
current_seq = 30857
count = 169
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.569702
last_received_ts = 741.569458
last_seq = 30857
current_ts = 741.586365
current_received_ts = 741.585815
current_seq = 30858
count = 170
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.586365
last_received_ts = 741.585815
last_seq = 30858
current_ts = 741.603027
current_received_ts = 741.602600
current_seq = 30859
count = 171
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.603027
last_received_ts = 741.602600
last_seq = 30859
current_ts = 741.619690
current_received_ts = 741.619446
current_seq = 30860
count = 172
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.619690
last_received_ts = 741.619446
last_seq = 30860
current_ts = 741.636353
current_received_ts = 741.636169
current_seq = 30861
count = 173
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 25us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.636353
last_received_ts = 741.636169
last_seq = 30861
current_ts = 741.653015
current_received_ts = 741.652527
current_seq = 30862
count = 174
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.653015
last_received_ts = 741.652527
last_seq = 30862
current_ts = 741.669678
current_received_ts = 741.669739
current_seq = 30863
count = 175
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.669678
last_received_ts = 741.669739
last_seq = 30863
current_ts = 741.686401
current_received_ts = 741.686279
current_seq = 30864
count = 176
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.686401
last_received_ts = 741.686279
last_seq = 30864
current_ts = 741.703064
current_received_ts = 741.702637
current_seq = 30865
count = 177
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.703064
last_received_ts = 741.702637
last_seq = 30865
current_ts = 741.719727
current_received_ts = 741.719849
current_seq = 30866
count = 178
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.719727
last_received_ts = 741.719849
last_seq = 30866
current_ts = 741.736389
current_received_ts = 741.735901
current_seq = 30867
count = 179
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 19us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.736389
last_received_ts = 741.735901
last_seq = 30867
current_ts = 741.753052
current_received_ts = 741.752625
current_seq = 30868
count = 180
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.753052
last_received_ts = 741.752625
last_seq = 30868
current_ts = 741.769714
current_received_ts = 741.769470
current_seq = 30869
count = 181
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.769714
last_received_ts = 741.769470
last_seq = 30869
current_ts = 741.786377
current_received_ts = 741.786255
current_seq = 30870
count = 182
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 25us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.786377
last_received_ts = 741.786255
last_seq = 30870
current_ts = 741.803040
current_received_ts = 741.802612
current_seq = 30871
count = 183
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.803040
last_received_ts = 741.802612
last_seq = 30871
current_ts = 741.819702
current_received_ts = 741.819946
current_seq = 30872
count = 184
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 59us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.819702
last_received_ts = 741.819946
last_seq = 30872
current_ts = 741.836365
current_received_ts = 741.836304
current_seq = 30873
count = 185
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.836365
last_received_ts = 741.836304
last_seq = 30873
current_ts = 741.853088
current_received_ts = 741.853088
current_seq = 30874
count = 186
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.853088
last_received_ts = 741.853088
last_seq = 30874
current_ts = 741.869751
current_received_ts = 741.869873
current_seq = 30875
count = 187
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.869751
last_received_ts = 741.869873
last_seq = 30875
current_ts = 741.886414
current_received_ts = 741.885925
current_seq = 30876
count = 188
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 65us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.886414
last_received_ts = 741.885925
last_seq = 30876
current_ts = 741.903076
current_received_ts = 741.902771
current_seq = 30877
count = 189
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.903076
last_received_ts = 741.902771
last_seq = 30877
current_ts = 741.919739
current_received_ts = 741.919495
current_seq = 30878
count = 190
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.919739
last_received_ts = 741.919495
last_seq = 30878
current_ts = 741.936401
current_received_ts = 741.935974
current_seq = 30879
count = 191
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.936401
last_received_ts = 741.935974
last_seq = 30879
current_ts = 741.953064
current_received_ts = 741.953125
current_seq = 30880
count = 192
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.953064
last_received_ts = 741.953125
last_seq = 30880
current_ts = 741.969788
current_received_ts = 741.969910
current_seq = 30881
count = 193
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.969788
last_received_ts = 741.969910
last_seq = 30881
current_ts = 741.986450
current_received_ts = 741.986267
current_seq = 30882
count = 194
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 741.986450
last_received_ts = 741.986267
last_seq = 30882
current_ts = 742.003113
current_received_ts = 742.002625
current_seq = 30883
count = 195
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.003113
last_received_ts = 742.002625
last_seq = 30883
current_ts = 742.019775
current_received_ts = 742.019836
current_seq = 30884
count = 196
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.019775
last_received_ts = 742.019836
last_seq = 30884
current_ts = 742.036438
current_received_ts = 742.035950
current_seq = 30885
count = 197
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 60us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.036438
last_received_ts = 742.035950
last_seq = 30885
current_ts = 742.053101
current_received_ts = 742.052795
current_seq = 30886
count = 198
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.053101
last_received_ts = 742.052795
last_seq = 30886
current_ts = 742.069763
current_received_ts = 742.069824
current_seq = 30887
count = 199
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.069763
last_received_ts = 742.069824
last_seq = 30887
current_ts = 742.086426
current_received_ts = 742.086243
current_seq = 30888
count = 200
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.086426
last_received_ts = 742.086243
last_seq = 30888
current_ts = 742.103088
current_received_ts = 742.102661
current_seq = 30889
count = 201
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.103088
last_received_ts = 742.102661
last_seq = 30889
current_ts = 742.119751
current_received_ts = 742.119934
current_seq = 30890
count = 202
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.119751
last_received_ts = 742.119934
last_seq = 30890
current_ts = 742.136475
current_received_ts = 742.136353
current_seq = 30891
count = 203
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.136475
last_received_ts = 742.136353
last_seq = 30891
current_ts = 742.153137
current_received_ts = 742.152649
current_seq = 30892
count = 204
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.153137
last_received_ts = 742.152649
last_seq = 30892
current_ts = 742.169800
current_received_ts = 742.169861
current_seq = 30893
count = 205
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.169800
last_received_ts = 742.169861
last_seq = 30893
current_ts = 742.186462
current_received_ts = 742.186096
current_seq = 30894
count = 206
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.186462
last_received_ts = 742.186096
last_seq = 30894
current_ts = 742.203125
current_received_ts = 742.203003
current_seq = 30895
count = 207
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.203125
last_received_ts = 742.203003
last_seq = 30895
current_ts = 742.219788
current_received_ts = 742.219482
current_seq = 30896
count = 208
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 25us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.219788
last_received_ts = 742.219482
last_seq = 30896
current_ts = 742.236450
current_received_ts = 742.236267
current_seq = 30897
count = 209
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.236450
last_received_ts = 742.236267
last_seq = 30897
current_ts = 742.253174
current_received_ts = 742.252686
current_seq = 30898
count = 210
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.253174
last_received_ts = 742.252686
last_seq = 30898
current_ts = 742.269836
current_received_ts = 742.269531
current_seq = 30899
count = 211
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.269836
last_received_ts = 742.269531
last_seq = 30899
current_ts = 742.286499
current_received_ts = 742.286621
current_seq = 30900
count = 212
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.286499
last_received_ts = 742.286621
last_seq = 30900
current_ts = 742.303162
current_received_ts = 742.302673
current_seq = 30901
count = 213
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 25us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.303162
last_received_ts = 742.302673
last_seq = 30901
current_ts = 742.319824
current_received_ts = 742.319458
current_seq = 30902
count = 214
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.319824
last_received_ts = 742.319458
last_seq = 30902
current_ts = 742.336487
current_received_ts = 742.336243
current_seq = 30903
count = 215
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.336487
last_received_ts = 742.336243
last_seq = 30903
current_ts = 742.353149
current_received_ts = 742.352722
current_seq = 30904
count = 216
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.353149
last_received_ts = 742.352722
last_seq = 30904
current_ts = 742.369812
current_received_ts = 742.369446
current_seq = 30905
count = 217
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.369812
last_received_ts = 742.369446
last_seq = 30905
current_ts = 742.386475
current_received_ts = 742.386658
current_seq = 30906
count = 218
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 19us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.386475
last_received_ts = 742.386658
last_seq = 30906
current_ts = 742.403137
current_received_ts = 742.403564
current_seq = 30907
count = 219
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.403137
last_received_ts = 742.403564
last_seq = 30907
current_ts = 742.419861
current_received_ts = 742.419861
current_seq = 30908
count = 220
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.419861
last_received_ts = 742.419861
last_seq = 30908
current_ts = 742.436523
current_received_ts = 742.436279
current_seq = 30909
count = 221
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.436523
last_received_ts = 742.436279
last_seq = 30909
current_ts = 742.453186
current_received_ts = 742.452942
current_seq = 30910
count = 222
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.453186
last_received_ts = 742.452942
last_seq = 30910
current_ts = 742.469849
current_received_ts = 742.469482
current_seq = 30911
count = 223
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.469849
last_received_ts = 742.469482
last_seq = 30911
current_ts = 742.486511
current_received_ts = 742.486755
current_seq = 30912
count = 224
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.486511
last_received_ts = 742.486755
last_seq = 30912
current_ts = 742.503174
current_received_ts = 742.502686
current_seq = 30913
count = 225
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.503174
last_received_ts = 742.502686
last_seq = 30913
current_ts = 742.519836
current_received_ts = 742.519531
current_seq = 30914
count = 226
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.519836
last_received_ts = 742.519531
last_seq = 30914
current_ts = 742.536499
current_received_ts = 742.536743
current_seq = 30915
count = 227
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.536499
last_received_ts = 742.536743
last_seq = 30915
current_ts = 742.553223
current_received_ts = 742.553040
current_seq = 30916
count = 228
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.553223
last_received_ts = 742.553040
last_seq = 30916
current_ts = 742.569885
current_received_ts = 742.569580
current_seq = 30917
count = 229
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.569885
last_received_ts = 742.569580
last_seq = 30917
current_ts = 742.586548
current_received_ts = 742.586121
current_seq = 30918
count = 230
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.586548
last_received_ts = 742.586121
last_seq = 30918
current_ts = 742.603210
current_received_ts = 742.602783
current_seq = 30919
count = 231
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.603210
last_received_ts = 742.602783
last_seq = 30919
current_ts = 742.619873
current_received_ts = 742.620056
current_seq = 30920
count = 232
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 35us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.619873
last_received_ts = 742.620056
last_seq = 30920
current_ts = 742.636536
current_received_ts = 742.636353
current_seq = 30921
count = 233
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.636536
last_received_ts = 742.636353
last_seq = 30921
current_ts = 742.653198
current_received_ts = 742.652832
current_seq = 30922
count = 234
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.653198
last_received_ts = 742.652832
last_seq = 30922
current_ts = 742.669922
current_received_ts = 742.669495
current_seq = 30923
count = 235
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.669922
last_received_ts = 742.669495
last_seq = 30923
current_ts = 742.686584
current_received_ts = 742.686707
current_seq = 30924
count = 236
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.686584
last_received_ts = 742.686707
last_seq = 30924
current_ts = 742.703247
current_received_ts = 742.703491
current_seq = 30925
count = 237
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.703247
last_received_ts = 742.703491
last_seq = 30925
current_ts = 742.719910
current_received_ts = 742.719849
current_seq = 30926
count = 238
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.719910
last_received_ts = 742.719849
last_seq = 30926
current_ts = 742.736572
current_received_ts = 742.736389
current_seq = 30927
count = 239
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.736572
last_received_ts = 742.736389
last_seq = 30927
current_ts = 742.753235
current_received_ts = 742.752991
current_seq = 30928
count = 240
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.753235
last_received_ts = 742.752991
last_seq = 30928
current_ts = 742.769897
current_received_ts = 742.769409
current_seq = 30929
count = 241
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.769897
last_received_ts = 742.769409
last_seq = 30929
current_ts = 742.786560
current_received_ts = 742.786621
current_seq = 30930
count = 242
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.786560
last_received_ts = 742.786621
last_seq = 30930
current_ts = 742.803223
current_received_ts = 742.803162
current_seq = 30931
count = 243
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.803223
last_received_ts = 742.803162
last_seq = 30931
current_ts = 742.819885
current_received_ts = 742.819458
current_seq = 30932
count = 244
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.819885
last_received_ts = 742.819458
last_seq = 30932
current_ts = 742.836609
current_received_ts = 742.836426
current_seq = 30933
count = 245
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 25us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.836609
last_received_ts = 742.836426
last_seq = 30933
current_ts = 742.853271
current_received_ts = 742.853088
current_seq = 30934
count = 246
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 25us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.853271
last_received_ts = 742.853088
last_seq = 30934
current_ts = 742.869934
current_received_ts = 742.869446
current_seq = 30935
count = 247
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.869934
last_received_ts = 742.869446
last_seq = 30935
current_ts = 742.886597
current_received_ts = 742.886475
current_seq = 30936
count = 248
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.886597
last_received_ts = 742.886475
last_seq = 30936
current_ts = 742.903259
current_received_ts = 742.903076
current_seq = 30937
count = 249
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.903259
last_received_ts = 742.903076
last_seq = 30937
current_ts = 742.919922
current_received_ts = 742.919861
current_seq = 30938
count = 250
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.919922
last_received_ts = 742.919861
last_seq = 30938
current_ts = 742.936584
current_received_ts = 742.936401
current_seq = 30939
count = 251
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.936584
last_received_ts = 742.936401
last_seq = 30939
current_ts = 742.953308
current_received_ts = 742.953552
current_seq = 30940
count = 252
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 19us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.953308
last_received_ts = 742.953552
last_seq = 30940
current_ts = 742.969971
current_received_ts = 742.969543
current_seq = 30941
count = 253
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.969971
last_received_ts = 742.969543
last_seq = 30941
current_ts = 742.986633
current_received_ts = 742.986450
current_seq = 30942
count = 254
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 742.986633
last_received_ts = 742.986450
last_seq = 30942
current_ts = 743.003296
current_received_ts = 743.003113
current_seq = 30943
count = 255
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.003296
last_received_ts = 743.003113
last_seq = 30943
current_ts = 743.019958
current_received_ts = 743.019531
current_seq = 30944
count = 256
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.019958
last_received_ts = 743.019531
last_seq = 30944
current_ts = 743.036621
current_received_ts = 743.036438
current_seq = 30945
count = 257
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.036621
last_received_ts = 743.036438
last_seq = 30945
current_ts = 743.053284
current_received_ts = 743.052795
current_seq = 30946
count = 258
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.053284
last_received_ts = 743.052795
last_seq = 30946
current_ts = 743.069946
current_received_ts = 743.070007
current_seq = 30947
count = 259
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.069946
last_received_ts = 743.070007
last_seq = 30947
current_ts = 743.086609
current_received_ts = 743.086426
current_seq = 30948
count = 260
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.086609
last_received_ts = 743.086426
last_seq = 30948
current_ts = 743.103271
current_received_ts = 743.103088
current_seq = 30949
count = 261
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.103271
last_received_ts = 743.103088
last_seq = 30949
current_ts = 743.119995
current_received_ts = 743.119507
current_seq = 30950
count = 262
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.119995
last_received_ts = 743.119507
last_seq = 30950
current_ts = 743.136658
current_received_ts = 743.136475
current_seq = 30951
count = 263
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.136658
last_received_ts = 743.136475
last_seq = 30951
current_ts = 743.153320
current_received_ts = 743.152771
current_seq = 30952
count = 264
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.153320
last_received_ts = 743.152771
last_seq = 30952
current_ts = 743.169983
current_received_ts = 743.169983
current_seq = 30953
count = 265
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.169983
last_received_ts = 743.169983
last_seq = 30953
current_ts = 743.186646
current_received_ts = 743.186401
current_seq = 30954
count = 266
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.186646
last_received_ts = 743.186401
last_seq = 30954
current_ts = 743.203308
current_received_ts = 743.203125
current_seq = 30955
count = 267
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.203308
last_received_ts = 743.203125
last_seq = 30955
current_ts = 743.219971
current_received_ts = 743.219543
current_seq = 30956
count = 268
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.219971
last_received_ts = 743.219543
last_seq = 30956
current_ts = 743.236633
current_received_ts = 743.236572
current_seq = 30957
count = 269
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.236633
last_received_ts = 743.236572
last_seq = 30957
current_ts = 743.253357
current_received_ts = 743.253601
current_seq = 30958
count = 270
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 20us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.253357
last_received_ts = 743.253601
last_seq = 30958
current_ts = 743.270020
current_received_ts = 743.269531
current_seq = 30959
count = 271
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.270020
last_received_ts = 743.269531
last_seq = 30959
current_ts = 743.286682
current_received_ts = 743.286499
current_seq = 30960
count = 272
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.286682
last_received_ts = 743.286499
last_seq = 30960
current_ts = 743.303345
current_received_ts = 743.302856
current_seq = 30961
count = 273
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.303345
last_received_ts = 743.302856
last_seq = 30961
current_ts = 743.320007
current_received_ts = 743.319641
current_seq = 30962
count = 274
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 25us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.320007
last_received_ts = 743.319641
last_seq = 30962
current_ts = 743.336670
current_received_ts = 743.336853
current_seq = 30963
count = 275
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.336670
last_received_ts = 743.336853
last_seq = 30963
current_ts = 743.353333
current_received_ts = 743.353149
current_seq = 30964
count = 276
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.353333
last_received_ts = 743.353149
last_seq = 30964
current_ts = 743.369995
current_received_ts = 743.369568
current_seq = 30965
count = 277
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 24us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.369995
last_received_ts = 743.369568
last_seq = 30965
current_ts = 743.386719
current_received_ts = 743.386658
current_seq = 30966
count = 278
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 21us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.386719
last_received_ts = 743.386658
last_seq = 30966
current_ts = 743.403381
current_received_ts = 743.403198
current_seq = 30967
count = 279
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.403381
last_received_ts = 743.403198
last_seq = 30967
current_ts = 743.420044
current_received_ts = 743.419556
current_seq = 30968
count = 280
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 23us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.420044
last_received_ts = 743.419556
last_seq = 30968
current_ts = 743.436707
current_received_ts = 743.436462
current_seq = 30969
count = 281
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 22us
(kms_flip:2546) DEBUG: name = flip
last_ts = 743.436707
last_received_ts = 743.436462
last_seq = 30969
current_ts = 743.453369
current_received_ts = 743.452881
current_seq = 30970
count = 282
seq_step = 1
(kms_flip:2546) DEBUG: Vblank took 941us
(kms_flip:2546) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2546) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2546) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2546) igt_core-INFO: Stack trace:
(kms_flip:2546) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2546) igt_core-INFO:   #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
(kms_flip:2546) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:2546) igt_core-INFO:   #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045()
(kms_flip:2546) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:2546) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2546) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2546) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A2: FAIL (5.319s)

Dmesg

<6> [738.320884] [IGT] kms_flip: starting dynamic subtest A-HDMI-A2

<7> [738.322538] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:179]

<7> [738.323560] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:182]

<7> [738.361929] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:77:pipe A]

<7> [738.362433] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:120:pipe B]

<7> [738.363080] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:163:pipe C]

<7> [738.363257] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.enable (expected yes, found no)

<7> [738.363866] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.active (expected yes, found no)

<7> [738.364365] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1)

<7> [738.364922] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in lane_count (expected 4, found 0)

<7> [738.365419] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000)

<7> [738.365939] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)

<7> [738.366434] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0)

<7> [738.366964] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)

<7> [738.367458] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)

<7> [738.367980] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)

<7> [738.368436] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)

<7> [738.368916] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)

<7> [738.369373] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)

<7> [738.369848] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)

<7> [738.370309] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)

<7> [738.370778] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0)

<7> [738.371235] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0)

<7> [738.371712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)

<7> [738.372171] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)

<7> [738.372625] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)

<7> [738.373097] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)

<7> [738.373556] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)

<7> [738.374030] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)

<7> [738.374486] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)

<7> [738.374953] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)

<7> [738.375409] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)

<7> [738.375883] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)

<7> [738.376339] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0)

<7> [738.376807] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0)

<7> [738.377265] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)

<7> [738.377738] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)

<7> [738.378197] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0)

<7> [738.378654] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)

<7> [738.379121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)

<7> [738.379590] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in has_hdmi_sink (expected yes, found no)

<7> [738.380070] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in has_infoframe (expected yes, found no)

<7> [738.380531] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in pipe_bpp (expected 36, found 0)

<7> [738.381015] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)

<7> [738.381474] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)

<7> [738.381949] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in port_clock (expected 222750, found 0)

<7> [738.382409] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000)

<7> [738.382878] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000)

<7> [738.383339] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in avi infoframe

<7> [738.383816] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [738.384272] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13

<7> [738.384277] i915 0000:00:02.0: colorspace: RGB

<7> [738.384281] i915 0000:00:02.0: scan mode: Underscan

<7> [738.384284] i915 0000:00:02.0: colorimetry: No Data

<7> [738.384288] i915 0000:00:02.0: picture aspect: No Data

<7> [738.384291] i915 0000:00:02.0: active aspect: Same as Picture

<7> [738.384295] i915 0000:00:02.0: itc: No Data

<7> [738.384298] i915 0000:00:02.0: extended colorimetry: xvYCC 601

<7> [738.384302] i915 0000:00:02.0: quantization range: Full

<7> [738.384305] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling

<7> [738.384309] i915 0000:00:02.0: video code: 0

<7> [738.384312] i915 0000:00:02.0: ycc quantization range: Full

<7> [738.384315] i915 0000:00:02.0: hdmi content type: Graphics

<7> [738.384319] i915 0000:00:02.0: pixel repeat: 0

<7> [738.384322] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0

<7> [738.384326] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [738.384793] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in spd infoframe

<7> [738.385250] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [738.385722] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25

<7> [738.385726] i915 0000:00:02.0: vendor: Intel

<7> [738.385730] i915 0000:00:02.0: product: Integrated gfx

<7> [738.385734] i915 0000:00:02.0: source device information: PC General (0x9)

<7> [738.385738] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [738.386205] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hdmi infoframe

<7> [738.386660] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [738.387128] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4

<7> [738.387133] i915 0000:00:02.0: empty frame

<7> [738.387136] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [738.387595] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:163:pipe C] fastset requirement not met, forcing full modeset

<7> [738.388073] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:163:pipe C] releasing PORT PLL B

<7> [738.389548] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:163:pipe C] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x4 -> 0x0

<7> [738.390225] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:157:cursor C] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0

<7> [738.391003] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:163:pipe C] min cdclk: 192000 kHz -> 0 kHz

<7> [738.391521] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change

<7> [738.392013] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz

<7> [738.392468] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4

<7> [738.392958] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:163:pipe C] enable: no [modeset]

<7> [738.393419] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:121:plane 1C] fb: [NOFB], visible: no

<7> [738.393892] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:130:plane 2C] fb: [NOFB], visible: no

<7> [738.394350] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:139:plane 3C] fb: [NOFB], visible: no

<7> [738.394830] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:148:plane 4C] fb: [NOFB], visible: no

<7> [738.395284] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:157:cursor C] fb: [NOFB], visible: no

<7> [738.396593] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:165:HDMI-A-1][ENCODER:164:DDI B/PHY B] Disable audio codec on [CRTC:163:pipe C]

<7> [738.429434] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port B

<7> [738.430430] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe C

<7> [738.442249] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10

<7> [738.447733] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time

<7> [738.553180] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B

<7> [738.554501] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL B (active 0x4, on? 1) for [CRTC:163:pipe C]

<7> [738.557787] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL B

<7> [738.558409] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 79200 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 4

<7> [738.559010] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B]

<7> [738.559508] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:174:DDI C/PHY C]

<7> [738.559999] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:165:HDMI-A-1]

<7> [738.560807] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-b

<7> [738.561419] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:163:pipe C]

<7> [738.562416] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:77:pipe A]

<7> [738.562508] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change

<7> [738.563075] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz

<7> [738.563560] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13

<7> [738.564394] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 316800 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 13

<7> [738.565823] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:175:HDMI-A-2]

<7> [738.566053] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36)

<7> [738.566606] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:77:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0

<7> [738.567153] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:174:DDI C/PHY C] [CRTC:77:pipe A]

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

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

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

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

<7> [738.569519] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d)

<7> [738.570002] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)

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

<7> [738.570942] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)

<7> [738.571398] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)

<7> [738.571877] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)

<7> [738.572333] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)

<7> [738.572816] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)

<7> [738.573274] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)

<7> [738.573748] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)

<7> [738.574204] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)

<7> [738.574687] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083)

<7> [738.575142] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088)

<7> [738.575599] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)

<7> [738.576076] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)

<7> [738.576532] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)

<7> [738.577016] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)

<7> [738.577475] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)

<7> [738.577954] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)

<7> [738.578411] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)

<7> [738.578895] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)

<7> [738.579354] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)

<7> [738.579829] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)

<7> [738.580286] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083)

<7> [738.580774] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088)

<7> [738.581234] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)

<7> [738.581712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)

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

<7> [738.582628] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)

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

<7> [738.583573] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes)

<7> [738.584051] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in has_infoframe (expected no, found yes)

<7> [738.584517] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)

<7> [738.585003] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)

<7> [738.585463] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)

<7> [738.585940] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in port_clock (expected 0, found 222750)

<7> [738.586402] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)

<7> [738.586893] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)

<7> [738.587350] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in avi infoframe

<7> [738.587831] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [738.588288] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [738.588782] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13

<7> [738.588787] i915 0000:00:02.0: colorspace: RGB

<7> [738.588791] i915 0000:00:02.0: scan mode: Underscan

<7> [738.588795] i915 0000:00:02.0: colorimetry: No Data

<7> [738.588798] i915 0000:00:02.0: picture aspect: No Data

<7> [738.588801] i915 0000:00:02.0: active aspect: Same as Picture

<7> [738.588805] i915 0000:00:02.0: itc: No Data

<7> [738.588808] i915 0000:00:02.0: extended colorimetry: xvYCC 601

<7> [738.588812] i915 0000:00:02.0: quantization range: Full

<7> [738.588815] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling

<7> [738.588819] i915 0000:00:02.0: video code: 0

<7> [738.588822] i915 0000:00:02.0: ycc quantization range: Full

<7> [738.588826] i915 0000:00:02.0: hdmi content type: Graphics

<7> [738.588829] i915 0000:00:02.0: pixel repeat: 0

<7> [738.588832] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0

<7> [738.588836] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in spd infoframe

<7> [738.589293] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [738.589766] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [738.590223] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25

<7> [738.590227] i915 0000:00:02.0: vendor: Intel

<7> [738.590231] i915 0000:00:02.0: product: Integrated gfx

<7> [738.590234] i915 0000:00:02.0: source device information: PC General (0x9)

<7> [738.590238] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hdmi infoframe

<7> [738.590722] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [738.591176] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [738.591628] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4

<7> [738.591637] i915 0000:00:02.0: empty frame

<7> [738.591662] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:77:pipe A] fastset requirement not met, forcing full modeset

<7> [738.592466] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:77:pipe A] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x1

<7> [738.593357] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988

<7> [738.593853] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:71:cursor A] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32

<7> [738.594300] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [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> [738.594768] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0

<7> [738.595215] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0

<7> [738.595690] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0

<7> [738.596385] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:77:pipe A] min cdclk: 0 kHz -> 192000 kHz

<7> [738.596930] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:77:pipe A] using pre-allocated PORT PLL C

<7> [738.597395] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:77:pipe A] reserving PORT PLL C

<7> [738.597894] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:77:pipe A] enable: yes [modeset]

<7> [738.598355] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB

<7> [738.598842] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0

<7> [738.599298] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>

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

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

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

<7> [738.601204] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71

<7> [738.601685] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6

<7> [738.602143] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13

<7> [738.602147] i915 0000:00:02.0: colorspace: RGB

<7> [738.602150] i915 0000:00:02.0: scan mode: Underscan

<7> [738.602154] i915 0000:00:02.0: colorimetry: No Data

<7> [738.602158] i915 0000:00:02.0: picture aspect: No Data

<7> [738.602161] i915 0000:00:02.0: active aspect: Same as Picture

<7> [738.602164] i915 0000:00:02.0: itc: No Data

<7> [738.602167] i915 0000:00:02.0: extended colorimetry: xvYCC 601

<7> [738.602171] i915 0000:00:02.0: quantization range: Full

<7> [738.602174] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling

<7> [738.602178] i915 0000:00:02.0: video code: 0

<7> [738.602181] i915 0000:00:02.0: ycc quantization range: Full

<7> [738.602184] i915 0000:00:02.0: hdmi content type: Graphics

<7> [738.602187] i915 0000:00:02.0: pixel repeat: 0

<7> [738.602191] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0

<7> [738.602195] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25

<7> [738.602198] i915 0000:00:02.0: vendor: Intel

<7> [738.602202] i915 0000:00:02.0: product: Integrated gfx

<7> [738.602205] i915 0000:00:02.0: source device information: PC General (0x9)

<7> [738.602209] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4

<7> [738.602213] i915 0000:00:02.0: empty frame

<7> [738.602216] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00

<7> [738.602702] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00

<7> [738.603160] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2

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

<7> [738.604091] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0

<7> [738.604548] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0

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

<7> [738.605486] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9

<7> [738.605961] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9

<7> [738.606418] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9

<7> [738.606904] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9

<7> [738.607363] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9

<7> [738.607841] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000

<7> [738.608300] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0

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

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

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

<7> [738.610181] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6200, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d

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

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

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

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

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

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

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

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

<7> [738.614378] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:179] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes

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

<7> [738.615321] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0

<7> [738.615796] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:44:plane 2A] fb: [NOFB], visible: no

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

<7> [738.616738] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:62:plane 4A] fb: [NOFB], visible: no

<7> [738.617197] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:71:cursor A] fb: [NOFB], visible: no

<7> [738.617754] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL

<7> [738.617770] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled

<7> [738.618479] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c

<7> [738.619444] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B]

<7> [738.619981] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:174:DDI C/PHY C]

<7> [738.620607] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x1, on? 0) for [CRTC:77:pipe A]

<7> [738.621102] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C

<7> [738.621826] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C

<7> [738.622387] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A

<7> [738.623801] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 16588800 bytes of contiguous stolen space for FBC, limit: 1

<7> [738.624261] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]

<7> [738.640723] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:175:HDMI-A-2][ENCODER:174:DDI C/PHY C] Enable audio codec on [CRTC:77:pipe A], 32 bytes ELD

<7> [738.657205] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000)

<7> [738.657809] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N

<7> [738.658508] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:175:HDMI-A-2]

<7> [738.660340] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:77:pipe A]

<6> [743.645581] [IGT] kms_flip: finished subtest A-HDMI-A2, FAIL

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