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

Detail	Value
Duration	2.93 seconds
Hostname	shard-glk6
Igt-Version	IGT-Version: 2.4-g55ccc746a (x86_64) (Linux: 7.0.0-Patchwork_164894v2-g19fc8405447f+ 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:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A2: FAIL (2.926s)
Err	Starting dynamic subtest: A-HDMI-A2 (kms_flip:2260) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2260) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2260) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-HDMI-A2 failed. ** DEBUG (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.570488 last_received_ts = 113.570206 last_seq = 1282 current_ts = 113.587158 current_received_ts = 113.586662 current_seq = 1283 count = 17 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.587158 last_received_ts = 113.586662 last_seq = 1283 current_ts = 113.603828 current_received_ts = 113.603409 current_seq = 1284 count = 18 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.603828 last_received_ts = 113.603409 last_seq = 1284 current_ts = 113.620491 current_received_ts = 113.620247 current_seq = 1285 count = 19 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.620491 last_received_ts = 113.620247 last_seq = 1285 current_ts = 113.637161 current_received_ts = 113.636803 current_seq = 1286 count = 20 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.637161 last_received_ts = 113.636803 last_seq = 1286 current_ts = 113.653824 current_received_ts = 113.653397 current_seq = 1287 count = 21 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.653824 last_received_ts = 113.653397 last_seq = 1287 current_ts = 113.670486 current_received_ts = 113.670181 current_seq = 1288 count = 22 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.670486 last_received_ts = 113.670181 last_seq = 1288 current_ts = 113.687157 current_received_ts = 113.686890 current_seq = 1289 count = 23 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.687157 last_received_ts = 113.686890 last_seq = 1289 current_ts = 113.703819 current_received_ts = 113.703773 current_seq = 1290 count = 24 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.703819 last_received_ts = 113.703773 last_seq = 1290 current_ts = 113.720490 current_received_ts = 113.720192 current_seq = 1291 count = 25 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.720490 last_received_ts = 113.720192 last_seq = 1291 current_ts = 113.737160 current_received_ts = 113.736839 current_seq = 1292 count = 26 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.737160 last_received_ts = 113.736839 last_seq = 1292 current_ts = 113.753838 current_received_ts = 113.753357 current_seq = 1293 count = 27 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 18us (kms_flip:2260) DEBUG: name = flip last_ts = 113.753838 last_received_ts = 113.753357 last_seq = 1293 current_ts = 113.770500 current_received_ts = 113.770462 current_seq = 1294 count = 28 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.770500 last_received_ts = 113.770462 last_seq = 1294 current_ts = 113.787170 current_received_ts = 113.786697 current_seq = 1295 count = 29 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.787170 last_received_ts = 113.786697 last_seq = 1295 current_ts = 113.803841 current_received_ts = 113.803406 current_seq = 1296 count = 30 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.803841 last_received_ts = 113.803406 last_seq = 1296 current_ts = 113.820503 current_received_ts = 113.820213 current_seq = 1297 count = 31 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.820503 last_received_ts = 113.820213 last_seq = 1297 current_ts = 113.837173 current_received_ts = 113.836906 current_seq = 1298 count = 32 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 113.837173 last_received_ts = 113.836906 last_seq = 1298 current_ts = 113.853844 current_received_ts = 113.853806 current_seq = 1299 count = 33 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.853844 last_received_ts = 113.853806 last_seq = 1299 current_ts = 113.870506 current_received_ts = 113.870247 current_seq = 1300 count = 34 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.870506 last_received_ts = 113.870247 last_seq = 1300 current_ts = 113.887177 current_received_ts = 113.886902 current_seq = 1301 count = 35 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.887177 last_received_ts = 113.886902 last_seq = 1301 current_ts = 113.903847 current_received_ts = 113.903343 current_seq = 1302 count = 36 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 113.903847 last_received_ts = 113.903343 last_seq = 1302 current_ts = 113.920502 current_received_ts = 113.920219 current_seq = 1303 count = 37 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 113.920502 last_received_ts = 113.920219 last_seq = 1303 current_ts = 113.937180 current_received_ts = 113.936943 current_seq = 1304 count = 38 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 65us (kms_flip:2260) DEBUG: name = flip last_ts = 113.937180 last_received_ts = 113.936943 last_seq = 1304 current_ts = 113.953842 current_received_ts = 113.953400 current_seq = 1305 count = 39 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 113.953842 last_received_ts = 113.953400 last_seq = 1305 current_ts = 113.970512 current_received_ts = 113.970261 current_seq = 1306 count = 40 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 113.970512 last_received_ts = 113.970261 last_seq = 1306 current_ts = 113.987175 current_received_ts = 113.986908 current_seq = 1307 count = 41 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 113.987175 last_received_ts = 113.986908 last_seq = 1307 current_ts = 114.003853 current_received_ts = 114.003799 current_seq = 1308 count = 42 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 114.003853 last_received_ts = 114.003799 last_seq = 1308 current_ts = 114.020515 current_received_ts = 114.020271 current_seq = 1309 count = 43 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 25us (kms_flip:2260) DEBUG: name = flip last_ts = 114.020515 last_received_ts = 114.020271 last_seq = 1309 current_ts = 114.037178 current_received_ts = 114.036858 current_seq = 1310 count = 44 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 114.037178 last_received_ts = 114.036858 last_seq = 1310 current_ts = 114.053856 current_received_ts = 114.053825 current_seq = 1311 count = 45 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 114.053856 last_received_ts = 114.053825 last_seq = 1311 current_ts = 114.070511 current_received_ts = 114.070221 current_seq = 1312 count = 46 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.070511 last_received_ts = 114.070221 last_seq = 1312 current_ts = 114.087196 current_received_ts = 114.086876 current_seq = 1313 count = 47 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.087196 last_received_ts = 114.086876 last_seq = 1313 current_ts = 114.103851 current_received_ts = 114.103409 current_seq = 1314 count = 48 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.103851 last_received_ts = 114.103409 last_seq = 1314 current_ts = 114.120522 current_received_ts = 114.120560 current_seq = 1315 count = 49 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.120522 last_received_ts = 114.120560 last_seq = 1315 current_ts = 114.137192 current_received_ts = 114.136688 current_seq = 1316 count = 50 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.137192 last_received_ts = 114.136688 last_seq = 1316 current_ts = 114.153862 current_received_ts = 114.153450 current_seq = 1317 count = 51 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 17us (kms_flip:2260) DEBUG: name = flip last_ts = 114.153862 last_received_ts = 114.153450 last_seq = 1317 current_ts = 114.170517 current_received_ts = 114.170662 current_seq = 1318 count = 52 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.170517 last_received_ts = 114.170662 last_seq = 1318 current_ts = 114.187195 current_received_ts = 114.187325 current_seq = 1319 count = 53 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 20us (kms_flip:2260) DEBUG: name = flip last_ts = 114.187195 last_received_ts = 114.187325 last_seq = 1319 current_ts = 114.203865 current_received_ts = 114.203453 current_seq = 1320 count = 54 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.203865 last_received_ts = 114.203453 last_seq = 1320 current_ts = 114.220528 current_received_ts = 114.220215 current_seq = 1321 count = 55 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.220528 last_received_ts = 114.220215 last_seq = 1321 current_ts = 114.237198 current_received_ts = 114.236893 current_seq = 1322 count = 56 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 114.237198 last_received_ts = 114.236893 last_seq = 1322 current_ts = 114.253868 current_received_ts = 114.253807 current_seq = 1323 count = 57 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.253868 last_received_ts = 114.253807 last_seq = 1323 current_ts = 114.270523 current_received_ts = 114.270241 current_seq = 1324 count = 58 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.270523 last_received_ts = 114.270241 last_seq = 1324 current_ts = 114.287201 current_received_ts = 114.286873 current_seq = 1325 count = 59 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.287201 last_received_ts = 114.286873 last_seq = 1325 current_ts = 114.303871 current_received_ts = 114.303391 current_seq = 1326 count = 60 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.303871 last_received_ts = 114.303391 last_seq = 1326 current_ts = 114.320526 current_received_ts = 114.320168 current_seq = 1327 count = 61 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.320526 last_received_ts = 114.320168 last_seq = 1327 current_ts = 114.337204 current_received_ts = 114.336884 current_seq = 1328 count = 62 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.337204 last_received_ts = 114.336884 last_seq = 1328 current_ts = 114.353867 current_received_ts = 114.353340 current_seq = 1329 count = 63 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 13us (kms_flip:2260) DEBUG: name = flip last_ts = 114.353867 last_received_ts = 114.353340 last_seq = 1329 current_ts = 114.370537 current_received_ts = 114.370232 current_seq = 1330 count = 64 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.370537 last_received_ts = 114.370232 last_seq = 1330 current_ts = 114.387215 current_received_ts = 114.386917 current_seq = 1331 count = 65 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 25us (kms_flip:2260) DEBUG: name = flip last_ts = 114.387215 last_received_ts = 114.386917 last_seq = 1331 current_ts = 114.403870 current_received_ts = 114.403824 current_seq = 1332 count = 66 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.403870 last_received_ts = 114.403824 last_seq = 1332 current_ts = 114.420540 current_received_ts = 114.420242 current_seq = 1333 count = 67 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 25us (kms_flip:2260) DEBUG: name = flip last_ts = 114.420540 last_received_ts = 114.420242 last_seq = 1333 current_ts = 114.437202 current_received_ts = 114.436935 current_seq = 1334 count = 68 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 91us (kms_flip:2260) DEBUG: name = flip last_ts = 114.437202 last_received_ts = 114.436935 last_seq = 1334 current_ts = 114.453880 current_received_ts = 114.453400 current_seq = 1335 count = 69 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.453880 last_received_ts = 114.453400 last_seq = 1335 current_ts = 114.470551 current_received_ts = 114.470360 current_seq = 1336 count = 70 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.470551 last_received_ts = 114.470360 last_seq = 1336 current_ts = 114.487213 current_received_ts = 114.486732 current_seq = 1337 count = 71 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.487213 last_received_ts = 114.486732 last_seq = 1337 current_ts = 114.503876 current_received_ts = 114.503807 current_seq = 1338 count = 72 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.503876 last_received_ts = 114.503807 last_seq = 1338 current_ts = 114.520546 current_received_ts = 114.520226 current_seq = 1339 count = 73 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.520546 last_received_ts = 114.520226 last_seq = 1339 current_ts = 114.537209 current_received_ts = 114.537216 current_seq = 1340 count = 74 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.537209 last_received_ts = 114.537216 last_seq = 1340 current_ts = 114.553886 current_received_ts = 114.553474 current_seq = 1341 count = 75 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.553886 last_received_ts = 114.553474 last_seq = 1341 current_ts = 114.570549 current_received_ts = 114.570290 current_seq = 1342 count = 76 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.570549 last_received_ts = 114.570290 last_seq = 1342 current_ts = 114.587212 current_received_ts = 114.586960 current_seq = 1343 count = 77 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.587212 last_received_ts = 114.586960 last_seq = 1343 current_ts = 114.603882 current_received_ts = 114.603806 current_seq = 1344 count = 78 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.603882 last_received_ts = 114.603806 last_seq = 1344 current_ts = 114.620552 current_received_ts = 114.620262 current_seq = 1345 count = 79 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.620552 last_received_ts = 114.620262 last_seq = 1345 current_ts = 114.637222 current_received_ts = 114.636749 current_seq = 1346 count = 80 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.637222 last_received_ts = 114.636749 last_seq = 1346 current_ts = 114.653893 current_received_ts = 114.653419 current_seq = 1347 count = 81 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.653893 last_received_ts = 114.653419 last_seq = 1347 current_ts = 114.670563 current_received_ts = 114.670181 current_seq = 1348 count = 82 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 25us (kms_flip:2260) DEBUG: name = flip last_ts = 114.670563 last_received_ts = 114.670181 last_seq = 1348 current_ts = 114.687218 current_received_ts = 114.686928 current_seq = 1349 count = 83 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 77us (kms_flip:2260) DEBUG: name = flip last_ts = 114.687218 last_received_ts = 114.686928 last_seq = 1349 current_ts = 114.703896 current_received_ts = 114.703842 current_seq = 1350 count = 84 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.703896 last_received_ts = 114.703842 last_seq = 1350 current_ts = 114.720558 current_received_ts = 114.720222 current_seq = 1351 count = 85 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.720558 last_received_ts = 114.720222 last_seq = 1351 current_ts = 114.737228 current_received_ts = 114.736969 current_seq = 1352 count = 86 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.737228 last_received_ts = 114.736969 last_seq = 1352 current_ts = 114.753899 current_received_ts = 114.753525 current_seq = 1353 count = 87 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 114.753899 last_received_ts = 114.753525 last_seq = 1353 current_ts = 114.770561 current_received_ts = 114.770233 current_seq = 1354 count = 88 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.770561 last_received_ts = 114.770233 last_seq = 1354 current_ts = 114.787224 current_received_ts = 114.786911 current_seq = 1355 count = 89 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.787224 last_received_ts = 114.786911 last_seq = 1355 current_ts = 114.803902 current_received_ts = 114.803841 current_seq = 1356 count = 90 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.803902 last_received_ts = 114.803841 last_seq = 1356 current_ts = 114.820564 current_received_ts = 114.820267 current_seq = 1357 count = 91 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.820564 last_received_ts = 114.820267 last_seq = 1357 current_ts = 114.837227 current_received_ts = 114.836906 current_seq = 1358 count = 92 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.837227 last_received_ts = 114.836906 last_seq = 1358 current_ts = 114.853905 current_received_ts = 114.853867 current_seq = 1359 count = 93 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.853905 last_received_ts = 114.853867 last_seq = 1359 current_ts = 114.870567 current_received_ts = 114.870293 current_seq = 1360 count = 94 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.870567 last_received_ts = 114.870293 last_seq = 1360 current_ts = 114.887238 current_received_ts = 114.886940 current_seq = 1361 count = 95 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 60us (kms_flip:2260) DEBUG: name = flip last_ts = 114.887238 last_received_ts = 114.886940 last_seq = 1361 current_ts = 114.903893 current_received_ts = 114.903831 current_seq = 1362 count = 96 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.903893 last_received_ts = 114.903831 last_seq = 1362 current_ts = 114.920570 current_received_ts = 114.920265 current_seq = 1363 count = 97 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 114.920570 last_received_ts = 114.920265 last_seq = 1363 current_ts = 114.937241 current_received_ts = 114.936752 current_seq = 1364 count = 98 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.937241 last_received_ts = 114.936752 last_seq = 1364 current_ts = 114.953911 current_received_ts = 114.953438 current_seq = 1365 count = 99 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 114.953911 last_received_ts = 114.953438 last_seq = 1365 current_ts = 114.970566 current_received_ts = 114.970116 current_seq = 1366 count = 100 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 114.970566 last_received_ts = 114.970116 last_seq = 1366 current_ts = 114.987244 current_received_ts = 114.986740 current_seq = 1367 count = 101 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 114.987244 last_received_ts = 114.986740 last_seq = 1367 current_ts = 115.003906 current_received_ts = 115.003906 current_seq = 1368 count = 102 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 115.003906 last_received_ts = 115.003906 last_seq = 1368 current_ts = 115.020576 current_received_ts = 115.020592 current_seq = 1369 count = 103 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 115.020576 last_received_ts = 115.020592 last_seq = 1369 current_ts = 115.037239 current_received_ts = 115.037476 current_seq = 1370 count = 104 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 115.037239 last_received_ts = 115.037476 last_seq = 1370 current_ts = 115.053902 current_received_ts = 115.053528 current_seq = 1371 count = 105 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 115.053902 last_received_ts = 115.053528 last_seq = 1371 current_ts = 115.070580 current_received_ts = 115.070305 current_seq = 1372 count = 106 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.070580 last_received_ts = 115.070305 last_seq = 1372 current_ts = 115.087250 current_received_ts = 115.086975 current_seq = 1373 count = 107 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 25us (kms_flip:2260) DEBUG: name = flip last_ts = 115.087250 last_received_ts = 115.086975 last_seq = 1373 current_ts = 115.103912 current_received_ts = 115.103867 current_seq = 1374 count = 108 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 115.103912 last_received_ts = 115.103867 last_seq = 1374 current_ts = 115.120583 current_received_ts = 115.120277 current_seq = 1375 count = 109 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 115.120583 last_received_ts = 115.120277 last_seq = 1375 current_ts = 115.137253 current_received_ts = 115.136932 current_seq = 1376 count = 110 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 56us (kms_flip:2260) DEBUG: name = flip last_ts = 115.137253 last_received_ts = 115.136932 last_seq = 1376 current_ts = 115.153915 current_received_ts = 115.153442 current_seq = 1377 count = 111 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.153915 last_received_ts = 115.153442 last_seq = 1377 current_ts = 115.170586 current_received_ts = 115.170692 current_seq = 1378 count = 112 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 115.170586 last_received_ts = 115.170692 last_seq = 1378 current_ts = 115.187256 current_received_ts = 115.186790 current_seq = 1379 count = 113 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 115.187256 last_received_ts = 115.186790 last_seq = 1379 current_ts = 115.203926 current_received_ts = 115.203453 current_seq = 1380 count = 114 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.203926 last_received_ts = 115.203453 last_seq = 1380 current_ts = 115.220589 current_received_ts = 115.220215 current_seq = 1381 count = 115 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 20us (kms_flip:2260) DEBUG: name = flip last_ts = 115.220589 last_received_ts = 115.220215 last_seq = 1381 current_ts = 115.237267 current_received_ts = 115.237350 current_seq = 1382 count = 116 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 19us (kms_flip:2260) DEBUG: name = flip last_ts = 115.237267 last_received_ts = 115.237350 last_seq = 1382 current_ts = 115.253929 current_received_ts = 115.253532 current_seq = 1383 count = 117 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.253929 last_received_ts = 115.253532 last_seq = 1383 current_ts = 115.270592 current_received_ts = 115.270294 current_seq = 1384 count = 118 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 115.270592 last_received_ts = 115.270294 last_seq = 1384 current_ts = 115.287262 current_received_ts = 115.286964 current_seq = 1385 count = 119 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 115.287262 last_received_ts = 115.286964 last_seq = 1385 current_ts = 115.303932 current_received_ts = 115.303482 current_seq = 1386 count = 120 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 25us (kms_flip:2260) DEBUG: name = flip last_ts = 115.303932 last_received_ts = 115.303482 last_seq = 1386 current_ts = 115.320595 current_received_ts = 115.320702 current_seq = 1387 count = 121 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 20us (kms_flip:2260) DEBUG: name = flip last_ts = 115.320595 last_received_ts = 115.320702 last_seq = 1387 current_ts = 115.337257 current_received_ts = 115.336922 current_seq = 1388 count = 122 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.337257 last_received_ts = 115.336922 last_seq = 1388 current_ts = 115.353928 current_received_ts = 115.353531 current_seq = 1389 count = 123 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 115.353928 last_received_ts = 115.353531 last_seq = 1389 current_ts = 115.370605 current_received_ts = 115.370316 current_seq = 1390 count = 124 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.370605 last_received_ts = 115.370316 last_seq = 1390 current_ts = 115.387268 current_received_ts = 115.386955 current_seq = 1391 count = 125 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 24us (kms_flip:2260) DEBUG: name = flip last_ts = 115.387268 last_received_ts = 115.386955 last_seq = 1391 current_ts = 115.403931 current_received_ts = 115.403465 current_seq = 1392 count = 126 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 115.403931 last_received_ts = 115.403465 last_seq = 1392 current_ts = 115.420593 current_received_ts = 115.420387 current_seq = 1393 count = 127 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 115.420593 last_received_ts = 115.420387 last_seq = 1393 current_ts = 115.437263 current_received_ts = 115.436928 current_seq = 1394 count = 128 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 58us (kms_flip:2260) DEBUG: name = flip last_ts = 115.437263 last_received_ts = 115.436928 last_seq = 1394 current_ts = 115.453941 current_received_ts = 115.453453 current_seq = 1395 count = 129 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 115.453941 last_received_ts = 115.453453 last_seq = 1395 current_ts = 115.470596 current_received_ts = 115.470238 current_seq = 1396 count = 130 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 20us (kms_flip:2260) DEBUG: name = flip last_ts = 115.470596 last_received_ts = 115.470238 last_seq = 1396 current_ts = 115.487267 current_received_ts = 115.487221 current_seq = 1397 count = 131 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.487267 last_received_ts = 115.487221 last_seq = 1397 current_ts = 115.503944 current_received_ts = 115.503571 current_seq = 1398 count = 132 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.503944 last_received_ts = 115.503571 last_seq = 1398 current_ts = 115.520615 current_received_ts = 115.520355 current_seq = 1399 count = 133 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 21us (kms_flip:2260) DEBUG: name = flip last_ts = 115.520615 last_received_ts = 115.520355 last_seq = 1399 current_ts = 115.537277 current_received_ts = 115.536972 current_seq = 1400 count = 134 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 22us (kms_flip:2260) DEBUG: name = flip last_ts = 115.537277 last_received_ts = 115.536972 last_seq = 1400 current_ts = 115.553940 current_received_ts = 115.553482 current_seq = 1401 count = 135 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 25us (kms_flip:2260) DEBUG: name = flip last_ts = 115.553940 last_received_ts = 115.553482 last_seq = 1401 current_ts = 115.570618 current_received_ts = 115.570282 current_seq = 1402 count = 136 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 23us (kms_flip:2260) DEBUG: name = flip last_ts = 115.570618 last_received_ts = 115.570282 last_seq = 1402 current_ts = 115.587280 current_received_ts = 115.586937 current_seq = 1403 count = 137 seq_step = 1 (kms_flip:2260) DEBUG: Vblank took 823us (kms_flip:2260) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2260) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2260) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2260) igt_core-INFO: Stack trace: (kms_flip:2260) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2260) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:2260) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:2260) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() (kms_flip:2260) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:2260) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2260) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2260) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A2: FAIL (2.926s)
Dmesg	<6> [113.160678] [IGT] kms_flip: starting dynamic subtest A-HDMI-A2 <7> [113.161653] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:182] <7> [113.161992] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:184] <7> [113.198667] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:78:pipe A] <7> [113.199088] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B] <7> [113.199475] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:164:pipe C] <7> [113.199646] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.enable (expected yes, found no) <7> [113.200190] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.active (expected yes, found no) <7> [113.200672] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1) <7> [113.201112] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in lane_count (expected 4, found 0) <7> [113.201574] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000) <7> [113.201975] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [113.202358] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [113.202871] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [113.203251] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [113.203699] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [113.204080] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [113.204488] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [113.204871] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [113.205253] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [113.205725] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [113.206106] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0) <7> [113.206525] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0) <7> [113.206974] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [113.207357] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [113.207762] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [113.208144] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [113.208611] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [113.209009] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [113.209426] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [113.209803] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [113.210178] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [113.210626] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [113.211011] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0) <7> [113.211425] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0) <7> [113.211805] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [113.212230] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [113.212635] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [113.213013] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [113.213502] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [113.213881] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in has_hdmi_sink (expected yes, found no) <7> [113.214260] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in has_infoframe (expected yes, found no) <7> [113.214664] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in pipe_bpp (expected 36, found 0) <7> [113.215066] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [113.215500] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [113.215903] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in port_clock (expected 222750, found 0) <7> [113.216279] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000) <7> [113.216721] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000) <7> [113.217104] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in avi infoframe <7> [113.217518] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [113.217926] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [113.217931] i915 0000:00:02.0: colorspace: RGB <7> [113.217935] i915 0000:00:02.0: scan mode: Underscan <7> [113.217938] i915 0000:00:02.0: colorimetry: No Data <7> [113.217941] i915 0000:00:02.0: picture aspect: No Data <7> [113.217945] i915 0000:00:02.0: active aspect: Same as Picture <7> [113.217948] i915 0000:00:02.0: itc: No Data <7> [113.217951] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [113.217955] i915 0000:00:02.0: quantization range: Full <7> [113.217957] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [113.217961] i915 0000:00:02.0: video code: 0 <7> [113.217964] i915 0000:00:02.0: ycc quantization range: Full <7> [113.217967] i915 0000:00:02.0: hdmi content type: Graphics <7> [113.217970] i915 0000:00:02.0: pixel repeat: 0 <7> [113.217973] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [113.217977] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [113.218357] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in spd infoframe <7> [113.218769] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [113.219144] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [113.219148] i915 0000:00:02.0: vendor: Intel <7> [113.219152] i915 0000:00:02.0: product: Integrated gfx <7> [113.219155] i915 0000:00:02.0: source device information: PC General (0x9) <7> [113.219159] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [113.219583] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hdmi infoframe <7> [113.219959] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [113.220335] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [113.220341] i915 0000:00:02.0: empty frame <7> [113.220345] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [113.220737] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:164:pipe C] fastset requirement not met, forcing full modeset <7> [113.221173] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:164:pipe C] releasing PORT PLL B <7> [113.221745] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:164:pipe C] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x4 -> 0x0 <7> [113.222181] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:158:cursor C] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0 <7> [113.222633] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:164:pipe C] min cdclk: 192000 kHz -> 0 kHz <7> [113.223061] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [113.223460] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz <7> [113.223839] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4 <7> [113.224249] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:164:pipe C] enable: no [modeset] <7> [113.224679] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:122:plane 1C] fb: [NOFB], visible: no <7> [113.225078] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:131:plane 2C] fb: [NOFB], visible: no <7> [113.225496] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:140:plane 3C] fb: [NOFB], visible: no <7> [113.225876] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:149:plane 4C] fb: [NOFB], visible: no <7> [113.226252] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:158:cursor C] fb: [NOFB], visible: no <7> [113.226844] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:166:HDMI-A-1][ENCODER:165:DDI B/PHY B] Disable audio codec on [CRTC:164:pipe C] <7> [113.257534] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port B <7> [113.259113] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe C <7> [113.271020] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10 <7> [113.275739] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time <7> [113.380744] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B <7> [113.381525] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL B (active 0x4, on? 1) for [CRTC:164:pipe C] <7> [113.382289] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL B <7> [113.384230] 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> [113.385161] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B] <7> [113.386149] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:175:DDI C/PHY C] <7> [113.386812] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:166:HDMI-A-1] <7> [113.387641] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-b <7> [113.388091] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:164:pipe C] <7> [113.389498] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [113.389927] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz <7> [113.390307] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13 <7> [113.390807] 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> [113.392612] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:78:pipe A] <7> [113.392680] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:176:HDMI-A-2] <7> [113.392876] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [113.393779] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:78:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [113.394179] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:175:DDI C/PHY C] [CRTC:78:pipe A] <7> [113.394910] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [113.395314] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [113.395934] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [113.396318] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [113.396912] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d) <7> [113.397298] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [113.397890] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL <7> [113.397907] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled <7> [113.398537] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [113.398944] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [113.399323] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [113.400652] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [113.401055] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [113.401948] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [113.402337] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [113.403087] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [113.403656] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [113.404038] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [113.404613] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [113.405005] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [113.406419] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [113.406835] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [113.407222] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [113.408038] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [113.408683] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [113.409065] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [113.409611] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [113.409994] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [113.410600] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [113.410983] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [113.412426] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [113.412848] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [113.413224] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [113.414072] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [113.414754] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [113.415141] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [113.415733] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [113.416115] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in has_infoframe (expected no, found yes) <7> [113.416673] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [113.417058] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [113.418368] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [113.418781] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in port_clock (expected 0, found 222750) <7> [113.419159] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [113.419901] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [113.420291] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in avi infoframe <7> [113.420946] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [113.421329] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [113.421900] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [113.421908] i915 0000:00:02.0: colorspace: RGB <7> [113.421912] i915 0000:00:02.0: scan mode: Underscan <7> [113.421916] i915 0000:00:02.0: colorimetry: No Data <7> [113.421919] i915 0000:00:02.0: picture aspect: No Data <7> [113.421923] i915 0000:00:02.0: active aspect: Same as Picture <7> [113.421926] i915 0000:00:02.0: itc: No Data <7> [113.421929] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [113.421933] i915 0000:00:02.0: quantization range: Full <7> [113.421936] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [113.421940] i915 0000:00:02.0: video code: 0 <7> [113.421943] i915 0000:00:02.0: ycc quantization range: Full <7> [113.421946] i915 0000:00:02.0: hdmi content type: Graphics <7> [113.421949] i915 0000:00:02.0: pixel repeat: 0 <7> [113.421952] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [113.421957] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in spd infoframe <7> [113.422337] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [113.423018] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [113.424685] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [113.424690] i915 0000:00:02.0: vendor: Intel <7> [113.424694] i915 0000:00:02.0: product: Integrated gfx <7> [113.424697] i915 0000:00:02.0: source device information: PC General (0x9) <7> [113.424701] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hdmi infoframe <7> [113.425114] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [113.425980] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [113.426634] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [113.426639] i915 0000:00:02.0: empty frame <7> [113.426644] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:78:pipe A] fastset requirement not met, forcing full modeset <7> [113.427110] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:78:pipe A] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x1 <7> [113.427785] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:36:plane 1A] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988 <7> [113.428167] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:72:cursor A] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32 <7> [113.428728] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [113.429107] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [113.430827] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [113.431247] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [113.432133] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36:plane 1A] min_ddb_uv 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [113.432833] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:78:pipe A] min cdclk: 0 kHz -> 192000 kHz <7> [113.433272] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:78:pipe A] using pre-allocated PORT PLL C <7> [113.433869] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:78:pipe A] reserving PORT PLL C <7> [113.434264] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:78:pipe A] enable: yes [modeset] <7> [113.434827] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [113.435209] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0 <7> [113.436550] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [113.436960] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [113.437340] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [113.438150] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [113.438808] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [113.439189] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [113.439738] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [113.439743] i915 0000:00:02.0: colorspace: RGB <7> [113.439748] i915 0000:00:02.0: scan mode: Underscan <7> [113.439751] i915 0000:00:02.0: colorimetry: No Data <7> [113.439755] i915 0000:00:02.0: picture aspect: No Data <7> [113.439758] i915 0000:00:02.0: active aspect: Same as Picture <7> [113.439762] i915 0000:00:02.0: itc: No Data <7> [113.439765] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [113.439768] i915 0000:00:02.0: quantization range: Full <7> [113.439771] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [113.439774] i915 0000:00:02.0: video code: 0 <7> [113.439777] i915 0000:00:02.0: ycc quantization range: Full <7> [113.439780] i915 0000:00:02.0: hdmi content type: Graphics <7> [113.439783] i915 0000:00:02.0: pixel repeat: 0 <7> [113.439786] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [113.439790] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [113.439793] i915 0000:00:02.0: vendor: Intel <7> [113.439797] i915 0000:00:02.0: product: Integrated gfx <7> [113.439800] i915 0000:00:02.0: source device information: PC General (0x9) <7> [113.439803] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [113.439807] i915 0000:00:02.0: empty frame <7> [113.439810] 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> [113.440189] 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> [113.440886] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [113.441276] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [113.443211] 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> [113.444123] 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> [113.444762] 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> [113.445146] 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> [113.445699] 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> [113.446084] 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> [113.446702] 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> [113.447085] 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> [113.447646] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pixel rate 148500, min cdclk 192000, min voltage level 0 <7> [113.448029] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0 <7> [113.449543] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [113.449953] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [113.450333] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [113.451169] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [113.451831] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [113.452214] 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> [113.452861] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [113.453244] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [113.453806] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [113.454185] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [113.455475] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [113.455873] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [113.456251] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [113.457002] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:36:plane 1A] fb: [FB:182] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [113.457634] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [113.458014] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [113.458624] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:45:plane 2A] fb: [NOFB], visible: no <7> [113.459005] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:plane 3A] fb: [NOFB], visible: no <7> [113.459558] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 4A] fb: [NOFB], visible: no <7> [113.459942] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:72:cursor A] fb: [NOFB], visible: no <7> [113.461174] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c <7> [113.461929] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B] <7> [113.462316] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:175:DDI C/PHY C] <7> [113.463052] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x1, on? 0) for [CRTC:78:pipe A] <7> [113.463612] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C <7> [113.464191] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C <7> [113.464878] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [113.465917] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 16588800 bytes of contiguous stolen space for FBC, limit: 1 <7> [113.466310] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:36:plane 1A] <7> [113.482597] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:176:HDMI-A-2][ENCODER:175:DDI C/PHY C] Enable audio codec on [CRTC:78:pipe A], 32 bytes ELD <7> [113.499234] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000) <7> [113.499743] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N <7> [113.500304] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:176:HDMI-A-2] <7> [113.501495] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:78:pipe A] <6> [116.091249] [IGT] kms_flip: finished subtest A-HDMI-A2, FAIL

Detail

Value

Duration

2.93 seconds

Hostname

shard-glk6

Igt-Version

IGT-Version: 2.4-g55ccc746a (x86_64) (Linux: 7.0.0-Patchwork_164894v2-g19fc8405447f+ 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:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A2: FAIL (2.926s)

Err

Starting dynamic subtest: A-HDMI-A2
(kms_flip:2260) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2260) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2260) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.570488
last_received_ts = 113.570206
last_seq = 1282
current_ts = 113.587158
current_received_ts = 113.586662
current_seq = 1283
count = 17
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.587158
last_received_ts = 113.586662
last_seq = 1283
current_ts = 113.603828
current_received_ts = 113.603409
current_seq = 1284
count = 18
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.603828
last_received_ts = 113.603409
last_seq = 1284
current_ts = 113.620491
current_received_ts = 113.620247
current_seq = 1285
count = 19
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.620491
last_received_ts = 113.620247
last_seq = 1285
current_ts = 113.637161
current_received_ts = 113.636803
current_seq = 1286
count = 20
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.637161
last_received_ts = 113.636803
last_seq = 1286
current_ts = 113.653824
current_received_ts = 113.653397
current_seq = 1287
count = 21
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.653824
last_received_ts = 113.653397
last_seq = 1287
current_ts = 113.670486
current_received_ts = 113.670181
current_seq = 1288
count = 22
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.670486
last_received_ts = 113.670181
last_seq = 1288
current_ts = 113.687157
current_received_ts = 113.686890
current_seq = 1289
count = 23
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.687157
last_received_ts = 113.686890
last_seq = 1289
current_ts = 113.703819
current_received_ts = 113.703773
current_seq = 1290
count = 24
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.703819
last_received_ts = 113.703773
last_seq = 1290
current_ts = 113.720490
current_received_ts = 113.720192
current_seq = 1291
count = 25
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.720490
last_received_ts = 113.720192
last_seq = 1291
current_ts = 113.737160
current_received_ts = 113.736839
current_seq = 1292
count = 26
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.737160
last_received_ts = 113.736839
last_seq = 1292
current_ts = 113.753838
current_received_ts = 113.753357
current_seq = 1293
count = 27
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 18us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.753838
last_received_ts = 113.753357
last_seq = 1293
current_ts = 113.770500
current_received_ts = 113.770462
current_seq = 1294
count = 28
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.770500
last_received_ts = 113.770462
last_seq = 1294
current_ts = 113.787170
current_received_ts = 113.786697
current_seq = 1295
count = 29
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.787170
last_received_ts = 113.786697
last_seq = 1295
current_ts = 113.803841
current_received_ts = 113.803406
current_seq = 1296
count = 30
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.803841
last_received_ts = 113.803406
last_seq = 1296
current_ts = 113.820503
current_received_ts = 113.820213
current_seq = 1297
count = 31
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.820503
last_received_ts = 113.820213
last_seq = 1297
current_ts = 113.837173
current_received_ts = 113.836906
current_seq = 1298
count = 32
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.837173
last_received_ts = 113.836906
last_seq = 1298
current_ts = 113.853844
current_received_ts = 113.853806
current_seq = 1299
count = 33
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.853844
last_received_ts = 113.853806
last_seq = 1299
current_ts = 113.870506
current_received_ts = 113.870247
current_seq = 1300
count = 34
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.870506
last_received_ts = 113.870247
last_seq = 1300
current_ts = 113.887177
current_received_ts = 113.886902
current_seq = 1301
count = 35
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.887177
last_received_ts = 113.886902
last_seq = 1301
current_ts = 113.903847
current_received_ts = 113.903343
current_seq = 1302
count = 36
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.903847
last_received_ts = 113.903343
last_seq = 1302
current_ts = 113.920502
current_received_ts = 113.920219
current_seq = 1303
count = 37
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.920502
last_received_ts = 113.920219
last_seq = 1303
current_ts = 113.937180
current_received_ts = 113.936943
current_seq = 1304
count = 38
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 65us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.937180
last_received_ts = 113.936943
last_seq = 1304
current_ts = 113.953842
current_received_ts = 113.953400
current_seq = 1305
count = 39
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.953842
last_received_ts = 113.953400
last_seq = 1305
current_ts = 113.970512
current_received_ts = 113.970261
current_seq = 1306
count = 40
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.970512
last_received_ts = 113.970261
last_seq = 1306
current_ts = 113.987175
current_received_ts = 113.986908
current_seq = 1307
count = 41
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 113.987175
last_received_ts = 113.986908
last_seq = 1307
current_ts = 114.003853
current_received_ts = 114.003799
current_seq = 1308
count = 42
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.003853
last_received_ts = 114.003799
last_seq = 1308
current_ts = 114.020515
current_received_ts = 114.020271
current_seq = 1309
count = 43
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 25us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.020515
last_received_ts = 114.020271
last_seq = 1309
current_ts = 114.037178
current_received_ts = 114.036858
current_seq = 1310
count = 44
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.037178
last_received_ts = 114.036858
last_seq = 1310
current_ts = 114.053856
current_received_ts = 114.053825
current_seq = 1311
count = 45
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.053856
last_received_ts = 114.053825
last_seq = 1311
current_ts = 114.070511
current_received_ts = 114.070221
current_seq = 1312
count = 46
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.070511
last_received_ts = 114.070221
last_seq = 1312
current_ts = 114.087196
current_received_ts = 114.086876
current_seq = 1313
count = 47
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.087196
last_received_ts = 114.086876
last_seq = 1313
current_ts = 114.103851
current_received_ts = 114.103409
current_seq = 1314
count = 48
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.103851
last_received_ts = 114.103409
last_seq = 1314
current_ts = 114.120522
current_received_ts = 114.120560
current_seq = 1315
count = 49
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.120522
last_received_ts = 114.120560
last_seq = 1315
current_ts = 114.137192
current_received_ts = 114.136688
current_seq = 1316
count = 50
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.137192
last_received_ts = 114.136688
last_seq = 1316
current_ts = 114.153862
current_received_ts = 114.153450
current_seq = 1317
count = 51
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 17us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.153862
last_received_ts = 114.153450
last_seq = 1317
current_ts = 114.170517
current_received_ts = 114.170662
current_seq = 1318
count = 52
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.170517
last_received_ts = 114.170662
last_seq = 1318
current_ts = 114.187195
current_received_ts = 114.187325
current_seq = 1319
count = 53
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 20us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.187195
last_received_ts = 114.187325
last_seq = 1319
current_ts = 114.203865
current_received_ts = 114.203453
current_seq = 1320
count = 54
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.203865
last_received_ts = 114.203453
last_seq = 1320
current_ts = 114.220528
current_received_ts = 114.220215
current_seq = 1321
count = 55
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.220528
last_received_ts = 114.220215
last_seq = 1321
current_ts = 114.237198
current_received_ts = 114.236893
current_seq = 1322
count = 56
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.237198
last_received_ts = 114.236893
last_seq = 1322
current_ts = 114.253868
current_received_ts = 114.253807
current_seq = 1323
count = 57
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.253868
last_received_ts = 114.253807
last_seq = 1323
current_ts = 114.270523
current_received_ts = 114.270241
current_seq = 1324
count = 58
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.270523
last_received_ts = 114.270241
last_seq = 1324
current_ts = 114.287201
current_received_ts = 114.286873
current_seq = 1325
count = 59
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.287201
last_received_ts = 114.286873
last_seq = 1325
current_ts = 114.303871
current_received_ts = 114.303391
current_seq = 1326
count = 60
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.303871
last_received_ts = 114.303391
last_seq = 1326
current_ts = 114.320526
current_received_ts = 114.320168
current_seq = 1327
count = 61
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.320526
last_received_ts = 114.320168
last_seq = 1327
current_ts = 114.337204
current_received_ts = 114.336884
current_seq = 1328
count = 62
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.337204
last_received_ts = 114.336884
last_seq = 1328
current_ts = 114.353867
current_received_ts = 114.353340
current_seq = 1329
count = 63
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 13us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.353867
last_received_ts = 114.353340
last_seq = 1329
current_ts = 114.370537
current_received_ts = 114.370232
current_seq = 1330
count = 64
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.370537
last_received_ts = 114.370232
last_seq = 1330
current_ts = 114.387215
current_received_ts = 114.386917
current_seq = 1331
count = 65
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 25us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.387215
last_received_ts = 114.386917
last_seq = 1331
current_ts = 114.403870
current_received_ts = 114.403824
current_seq = 1332
count = 66
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.403870
last_received_ts = 114.403824
last_seq = 1332
current_ts = 114.420540
current_received_ts = 114.420242
current_seq = 1333
count = 67
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 25us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.420540
last_received_ts = 114.420242
last_seq = 1333
current_ts = 114.437202
current_received_ts = 114.436935
current_seq = 1334
count = 68
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 91us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.437202
last_received_ts = 114.436935
last_seq = 1334
current_ts = 114.453880
current_received_ts = 114.453400
current_seq = 1335
count = 69
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.453880
last_received_ts = 114.453400
last_seq = 1335
current_ts = 114.470551
current_received_ts = 114.470360
current_seq = 1336
count = 70
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.470551
last_received_ts = 114.470360
last_seq = 1336
current_ts = 114.487213
current_received_ts = 114.486732
current_seq = 1337
count = 71
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.487213
last_received_ts = 114.486732
last_seq = 1337
current_ts = 114.503876
current_received_ts = 114.503807
current_seq = 1338
count = 72
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.503876
last_received_ts = 114.503807
last_seq = 1338
current_ts = 114.520546
current_received_ts = 114.520226
current_seq = 1339
count = 73
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.520546
last_received_ts = 114.520226
last_seq = 1339
current_ts = 114.537209
current_received_ts = 114.537216
current_seq = 1340
count = 74
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.537209
last_received_ts = 114.537216
last_seq = 1340
current_ts = 114.553886
current_received_ts = 114.553474
current_seq = 1341
count = 75
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.553886
last_received_ts = 114.553474
last_seq = 1341
current_ts = 114.570549
current_received_ts = 114.570290
current_seq = 1342
count = 76
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.570549
last_received_ts = 114.570290
last_seq = 1342
current_ts = 114.587212
current_received_ts = 114.586960
current_seq = 1343
count = 77
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.587212
last_received_ts = 114.586960
last_seq = 1343
current_ts = 114.603882
current_received_ts = 114.603806
current_seq = 1344
count = 78
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.603882
last_received_ts = 114.603806
last_seq = 1344
current_ts = 114.620552
current_received_ts = 114.620262
current_seq = 1345
count = 79
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.620552
last_received_ts = 114.620262
last_seq = 1345
current_ts = 114.637222
current_received_ts = 114.636749
current_seq = 1346
count = 80
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.637222
last_received_ts = 114.636749
last_seq = 1346
current_ts = 114.653893
current_received_ts = 114.653419
current_seq = 1347
count = 81
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.653893
last_received_ts = 114.653419
last_seq = 1347
current_ts = 114.670563
current_received_ts = 114.670181
current_seq = 1348
count = 82
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 25us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.670563
last_received_ts = 114.670181
last_seq = 1348
current_ts = 114.687218
current_received_ts = 114.686928
current_seq = 1349
count = 83
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 77us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.687218
last_received_ts = 114.686928
last_seq = 1349
current_ts = 114.703896
current_received_ts = 114.703842
current_seq = 1350
count = 84
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.703896
last_received_ts = 114.703842
last_seq = 1350
current_ts = 114.720558
current_received_ts = 114.720222
current_seq = 1351
count = 85
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.720558
last_received_ts = 114.720222
last_seq = 1351
current_ts = 114.737228
current_received_ts = 114.736969
current_seq = 1352
count = 86
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.737228
last_received_ts = 114.736969
last_seq = 1352
current_ts = 114.753899
current_received_ts = 114.753525
current_seq = 1353
count = 87
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.753899
last_received_ts = 114.753525
last_seq = 1353
current_ts = 114.770561
current_received_ts = 114.770233
current_seq = 1354
count = 88
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.770561
last_received_ts = 114.770233
last_seq = 1354
current_ts = 114.787224
current_received_ts = 114.786911
current_seq = 1355
count = 89
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.787224
last_received_ts = 114.786911
last_seq = 1355
current_ts = 114.803902
current_received_ts = 114.803841
current_seq = 1356
count = 90
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.803902
last_received_ts = 114.803841
last_seq = 1356
current_ts = 114.820564
current_received_ts = 114.820267
current_seq = 1357
count = 91
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.820564
last_received_ts = 114.820267
last_seq = 1357
current_ts = 114.837227
current_received_ts = 114.836906
current_seq = 1358
count = 92
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.837227
last_received_ts = 114.836906
last_seq = 1358
current_ts = 114.853905
current_received_ts = 114.853867
current_seq = 1359
count = 93
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.853905
last_received_ts = 114.853867
last_seq = 1359
current_ts = 114.870567
current_received_ts = 114.870293
current_seq = 1360
count = 94
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.870567
last_received_ts = 114.870293
last_seq = 1360
current_ts = 114.887238
current_received_ts = 114.886940
current_seq = 1361
count = 95
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 60us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.887238
last_received_ts = 114.886940
last_seq = 1361
current_ts = 114.903893
current_received_ts = 114.903831
current_seq = 1362
count = 96
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.903893
last_received_ts = 114.903831
last_seq = 1362
current_ts = 114.920570
current_received_ts = 114.920265
current_seq = 1363
count = 97
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.920570
last_received_ts = 114.920265
last_seq = 1363
current_ts = 114.937241
current_received_ts = 114.936752
current_seq = 1364
count = 98
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.937241
last_received_ts = 114.936752
last_seq = 1364
current_ts = 114.953911
current_received_ts = 114.953438
current_seq = 1365
count = 99
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.953911
last_received_ts = 114.953438
last_seq = 1365
current_ts = 114.970566
current_received_ts = 114.970116
current_seq = 1366
count = 100
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.970566
last_received_ts = 114.970116
last_seq = 1366
current_ts = 114.987244
current_received_ts = 114.986740
current_seq = 1367
count = 101
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 114.987244
last_received_ts = 114.986740
last_seq = 1367
current_ts = 115.003906
current_received_ts = 115.003906
current_seq = 1368
count = 102
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.003906
last_received_ts = 115.003906
last_seq = 1368
current_ts = 115.020576
current_received_ts = 115.020592
current_seq = 1369
count = 103
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.020576
last_received_ts = 115.020592
last_seq = 1369
current_ts = 115.037239
current_received_ts = 115.037476
current_seq = 1370
count = 104
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.037239
last_received_ts = 115.037476
last_seq = 1370
current_ts = 115.053902
current_received_ts = 115.053528
current_seq = 1371
count = 105
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.053902
last_received_ts = 115.053528
last_seq = 1371
current_ts = 115.070580
current_received_ts = 115.070305
current_seq = 1372
count = 106
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.070580
last_received_ts = 115.070305
last_seq = 1372
current_ts = 115.087250
current_received_ts = 115.086975
current_seq = 1373
count = 107
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 25us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.087250
last_received_ts = 115.086975
last_seq = 1373
current_ts = 115.103912
current_received_ts = 115.103867
current_seq = 1374
count = 108
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.103912
last_received_ts = 115.103867
last_seq = 1374
current_ts = 115.120583
current_received_ts = 115.120277
current_seq = 1375
count = 109
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.120583
last_received_ts = 115.120277
last_seq = 1375
current_ts = 115.137253
current_received_ts = 115.136932
current_seq = 1376
count = 110
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 56us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.137253
last_received_ts = 115.136932
last_seq = 1376
current_ts = 115.153915
current_received_ts = 115.153442
current_seq = 1377
count = 111
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.153915
last_received_ts = 115.153442
last_seq = 1377
current_ts = 115.170586
current_received_ts = 115.170692
current_seq = 1378
count = 112
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.170586
last_received_ts = 115.170692
last_seq = 1378
current_ts = 115.187256
current_received_ts = 115.186790
current_seq = 1379
count = 113
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.187256
last_received_ts = 115.186790
last_seq = 1379
current_ts = 115.203926
current_received_ts = 115.203453
current_seq = 1380
count = 114
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.203926
last_received_ts = 115.203453
last_seq = 1380
current_ts = 115.220589
current_received_ts = 115.220215
current_seq = 1381
count = 115
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 20us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.220589
last_received_ts = 115.220215
last_seq = 1381
current_ts = 115.237267
current_received_ts = 115.237350
current_seq = 1382
count = 116
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 19us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.237267
last_received_ts = 115.237350
last_seq = 1382
current_ts = 115.253929
current_received_ts = 115.253532
current_seq = 1383
count = 117
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.253929
last_received_ts = 115.253532
last_seq = 1383
current_ts = 115.270592
current_received_ts = 115.270294
current_seq = 1384
count = 118
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.270592
last_received_ts = 115.270294
last_seq = 1384
current_ts = 115.287262
current_received_ts = 115.286964
current_seq = 1385
count = 119
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.287262
last_received_ts = 115.286964
last_seq = 1385
current_ts = 115.303932
current_received_ts = 115.303482
current_seq = 1386
count = 120
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 25us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.303932
last_received_ts = 115.303482
last_seq = 1386
current_ts = 115.320595
current_received_ts = 115.320702
current_seq = 1387
count = 121
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 20us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.320595
last_received_ts = 115.320702
last_seq = 1387
current_ts = 115.337257
current_received_ts = 115.336922
current_seq = 1388
count = 122
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.337257
last_received_ts = 115.336922
last_seq = 1388
current_ts = 115.353928
current_received_ts = 115.353531
current_seq = 1389
count = 123
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.353928
last_received_ts = 115.353531
last_seq = 1389
current_ts = 115.370605
current_received_ts = 115.370316
current_seq = 1390
count = 124
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.370605
last_received_ts = 115.370316
last_seq = 1390
current_ts = 115.387268
current_received_ts = 115.386955
current_seq = 1391
count = 125
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 24us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.387268
last_received_ts = 115.386955
last_seq = 1391
current_ts = 115.403931
current_received_ts = 115.403465
current_seq = 1392
count = 126
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.403931
last_received_ts = 115.403465
last_seq = 1392
current_ts = 115.420593
current_received_ts = 115.420387
current_seq = 1393
count = 127
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.420593
last_received_ts = 115.420387
last_seq = 1393
current_ts = 115.437263
current_received_ts = 115.436928
current_seq = 1394
count = 128
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 58us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.437263
last_received_ts = 115.436928
last_seq = 1394
current_ts = 115.453941
current_received_ts = 115.453453
current_seq = 1395
count = 129
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.453941
last_received_ts = 115.453453
last_seq = 1395
current_ts = 115.470596
current_received_ts = 115.470238
current_seq = 1396
count = 130
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 20us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.470596
last_received_ts = 115.470238
last_seq = 1396
current_ts = 115.487267
current_received_ts = 115.487221
current_seq = 1397
count = 131
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.487267
last_received_ts = 115.487221
last_seq = 1397
current_ts = 115.503944
current_received_ts = 115.503571
current_seq = 1398
count = 132
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.503944
last_received_ts = 115.503571
last_seq = 1398
current_ts = 115.520615
current_received_ts = 115.520355
current_seq = 1399
count = 133
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 21us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.520615
last_received_ts = 115.520355
last_seq = 1399
current_ts = 115.537277
current_received_ts = 115.536972
current_seq = 1400
count = 134
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 22us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.537277
last_received_ts = 115.536972
last_seq = 1400
current_ts = 115.553940
current_received_ts = 115.553482
current_seq = 1401
count = 135
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 25us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.553940
last_received_ts = 115.553482
last_seq = 1401
current_ts = 115.570618
current_received_ts = 115.570282
current_seq = 1402
count = 136
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 23us
(kms_flip:2260) DEBUG: name = flip
last_ts = 115.570618
last_received_ts = 115.570282
last_seq = 1402
current_ts = 115.587280
current_received_ts = 115.586937
current_seq = 1403
count = 137
seq_step = 1
(kms_flip:2260) DEBUG: Vblank took 823us
(kms_flip:2260) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2260) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2260) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2260) igt_core-INFO: Stack trace:
(kms_flip:2260) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2260) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2260) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2260) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2260) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2260) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2260) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2260) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A2: FAIL (2.926s)

Dmesg

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

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

<7> [113.161992] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:184]

<7> [113.198667] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:78:pipe A]

<7> [113.199088] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B]

<7> [113.199475] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:164:pipe C]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [113.384230] 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> [113.385161] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B]

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

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

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

<7> [113.388091] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:164:pipe C]

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

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

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

<7> [113.390807] 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> [113.392612] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:78:pipe A]

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

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

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

<7> [113.394179] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:175:DDI C/PHY C] [CRTC:78:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [113.427785] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:36:plane 1A] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988

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

<7> [113.428728] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [113.429107] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [113.430827] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [113.431247] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [113.432133] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36:plane 1A] min_ddb_uv 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [113.439810] 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> [113.440189] 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> [113.440886] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2

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

<7> [113.443211] 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> [113.444123] 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> [113.444762] 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> [113.445146] 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> [113.445699] 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> [113.446084] 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> [113.446702] 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> [113.447085] 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> [113.447646] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pixel rate 148500, min cdclk 192000, min voltage level 0

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

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

<7> [113.449953] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0

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

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

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

<7> [113.452214] 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> [113.452861] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [113.501495] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:78:pipe A]

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

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