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

Detail	Value
Duration	3.45 seconds
Hostname	shard-glk8
Igt-Version	IGT-Version: 2.3-g23fdc238d (x86_64) (Linux: 7.0.0-rc3-CI_DRM_18143-g45618ec6cfed+ x86_64)
Out	Starting dynamic subtest: A-HDMI-A2 1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1887 run_test() #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2043() #4 ../tests/kms_flip.c:2043 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A2: FAIL (3.450s)
Err	Starting dynamic subtest: A-HDMI-A2 (kms_flip:2649) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:2649) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2649) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-HDMI-A2 failed. ** DEBUG (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 623.818054 last_received_ts = 623.817566 last_seq = 26296 current_ts = 623.834656 current_received_ts = 623.834290 current_seq = 26297 count = 48 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 623.834656 last_received_ts = 623.834290 last_seq = 26297 current_ts = 623.851379 current_received_ts = 623.850830 current_seq = 26298 count = 49 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 623.851379 last_received_ts = 623.850830 last_seq = 26298 current_ts = 623.868042 current_received_ts = 623.867676 current_seq = 26299 count = 50 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 623.868042 last_received_ts = 623.867676 last_seq = 26299 current_ts = 623.884705 current_received_ts = 623.884521 current_seq = 26300 count = 51 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 623.884705 last_received_ts = 623.884521 last_seq = 26300 current_ts = 623.901306 current_received_ts = 623.901184 current_seq = 26301 count = 52 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 623.901306 last_received_ts = 623.901184 last_seq = 26301 current_ts = 623.918030 current_received_ts = 623.917542 current_seq = 26302 count = 53 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 623.918030 last_received_ts = 623.917542 last_seq = 26302 current_ts = 623.934631 current_received_ts = 623.934448 current_seq = 26303 count = 54 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 623.934631 last_received_ts = 623.934448 last_seq = 26303 current_ts = 623.951355 current_received_ts = 623.950806 current_seq = 26304 count = 55 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 623.951355 last_received_ts = 623.950806 last_seq = 26304 current_ts = 623.968018 current_received_ts = 623.967590 current_seq = 26305 count = 56 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 623.968018 last_received_ts = 623.967590 last_seq = 26305 current_ts = 623.984680 current_received_ts = 623.984436 current_seq = 26306 count = 57 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 623.984680 last_received_ts = 623.984436 last_seq = 26306 current_ts = 624.001282 current_received_ts = 624.001099 current_seq = 26307 count = 58 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 624.001282 last_received_ts = 624.001099 last_seq = 26307 current_ts = 624.018005 current_received_ts = 624.017578 current_seq = 26308 count = 59 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.018005 last_received_ts = 624.017578 last_seq = 26308 current_ts = 624.034668 current_received_ts = 624.034729 current_seq = 26309 count = 60 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 624.034668 last_received_ts = 624.034729 last_seq = 26309 current_ts = 624.051270 current_received_ts = 624.051147 current_seq = 26310 count = 61 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 624.051270 last_received_ts = 624.051147 last_seq = 26310 current_ts = 624.067993 current_received_ts = 624.067566 current_seq = 26311 count = 62 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.067993 last_received_ts = 624.067566 last_seq = 26311 current_ts = 624.084595 current_received_ts = 624.084717 current_seq = 26312 count = 63 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.084595 last_received_ts = 624.084717 last_seq = 26312 current_ts = 624.101318 current_received_ts = 624.101196 current_seq = 26313 count = 64 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.101318 last_received_ts = 624.101196 last_seq = 26313 current_ts = 624.117981 current_received_ts = 624.117859 current_seq = 26314 count = 65 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.117981 last_received_ts = 624.117859 last_seq = 26314 current_ts = 624.134644 current_received_ts = 624.134460 current_seq = 26315 count = 66 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.134644 last_received_ts = 624.134460 last_seq = 26315 current_ts = 624.151306 current_received_ts = 624.150818 current_seq = 26316 count = 67 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.151306 last_received_ts = 624.150818 last_seq = 26316 current_ts = 624.167908 current_received_ts = 624.167542 current_seq = 26317 count = 68 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 624.167908 last_received_ts = 624.167542 last_seq = 26317 current_ts = 624.184631 current_received_ts = 624.184448 current_seq = 26318 count = 69 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 624.184631 last_received_ts = 624.184448 last_seq = 26318 current_ts = 624.201294 current_received_ts = 624.201111 current_seq = 26319 count = 70 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 624.201294 last_received_ts = 624.201111 last_seq = 26319 current_ts = 624.217896 current_received_ts = 624.217529 current_seq = 26320 count = 71 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.217896 last_received_ts = 624.217529 last_seq = 26320 current_ts = 624.234619 current_received_ts = 624.234863 current_seq = 26321 count = 72 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.234619 last_received_ts = 624.234863 last_seq = 26321 current_ts = 624.251282 current_received_ts = 624.250732 current_seq = 26322 count = 73 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 20us (kms_flip:2649) DEBUG: name = flip last_ts = 624.251282 last_received_ts = 624.250732 last_seq = 26322 current_ts = 624.267944 current_received_ts = 624.267517 current_seq = 26323 count = 74 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.267944 last_received_ts = 624.267517 last_seq = 26323 current_ts = 624.284607 current_received_ts = 624.284424 current_seq = 26324 count = 75 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.284607 last_received_ts = 624.284424 last_seq = 26324 current_ts = 624.301270 current_received_ts = 624.301086 current_seq = 26325 count = 76 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 624.301270 last_received_ts = 624.301086 last_seq = 26325 current_ts = 624.317932 current_received_ts = 624.317383 current_seq = 26326 count = 77 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 624.317932 last_received_ts = 624.317383 last_seq = 26326 current_ts = 624.334595 current_received_ts = 624.334473 current_seq = 26327 count = 78 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.334595 last_received_ts = 624.334473 last_seq = 26327 current_ts = 624.351257 current_received_ts = 624.350830 current_seq = 26328 count = 79 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 624.351257 last_received_ts = 624.350830 last_seq = 26328 current_ts = 624.367920 current_received_ts = 624.367859 current_seq = 26329 count = 80 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.367920 last_received_ts = 624.367859 last_seq = 26329 current_ts = 624.384583 current_received_ts = 624.384460 current_seq = 26330 count = 81 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.384583 last_received_ts = 624.384460 last_seq = 26330 current_ts = 624.401245 current_received_ts = 624.400696 current_seq = 26331 count = 82 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.401245 last_received_ts = 624.400696 last_seq = 26331 current_ts = 624.417908 current_received_ts = 624.417480 current_seq = 26332 count = 83 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.417908 last_received_ts = 624.417480 last_seq = 26332 current_ts = 624.434570 current_received_ts = 624.434692 current_seq = 26333 count = 84 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 624.434570 last_received_ts = 624.434692 last_seq = 26333 current_ts = 624.451233 current_received_ts = 624.450867 current_seq = 26334 count = 85 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.451233 last_received_ts = 624.450867 last_seq = 26334 current_ts = 624.467896 current_received_ts = 624.467896 current_seq = 26335 count = 86 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.467896 last_received_ts = 624.467896 last_seq = 26335 current_ts = 624.484558 current_received_ts = 624.484131 current_seq = 26336 count = 87 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.484558 last_received_ts = 624.484131 last_seq = 26336 current_ts = 624.501221 current_received_ts = 624.500732 current_seq = 26337 count = 88 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.501221 last_received_ts = 624.500732 last_seq = 26337 current_ts = 624.517883 current_received_ts = 624.517456 current_seq = 26338 count = 89 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.517883 last_received_ts = 624.517456 last_seq = 26338 current_ts = 624.534546 current_received_ts = 624.534363 current_seq = 26339 count = 90 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 624.534546 last_received_ts = 624.534363 last_seq = 26339 current_ts = 624.551208 current_received_ts = 624.550720 current_seq = 26340 count = 91 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 624.551208 last_received_ts = 624.550720 last_seq = 26340 current_ts = 624.567871 current_received_ts = 624.567505 current_seq = 26341 count = 92 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.567871 last_received_ts = 624.567505 last_seq = 26341 current_ts = 624.584534 current_received_ts = 624.584045 current_seq = 26342 count = 93 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.584534 last_received_ts = 624.584045 last_seq = 26342 current_ts = 624.601196 current_received_ts = 624.601501 current_seq = 26343 count = 94 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 20us (kms_flip:2649) DEBUG: name = flip last_ts = 624.601196 last_received_ts = 624.601501 last_seq = 26343 current_ts = 624.617859 current_received_ts = 624.617920 current_seq = 26344 count = 95 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 624.617859 last_received_ts = 624.617920 last_seq = 26344 current_ts = 624.634521 current_received_ts = 624.634338 current_seq = 26345 count = 96 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.634521 last_received_ts = 624.634338 last_seq = 26345 current_ts = 624.651184 current_received_ts = 624.650818 current_seq = 26346 count = 97 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 624.651184 last_received_ts = 624.650818 last_seq = 26346 current_ts = 624.667847 current_received_ts = 624.667908 current_seq = 26347 count = 98 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 61us (kms_flip:2649) DEBUG: name = flip last_ts = 624.667847 last_received_ts = 624.667908 last_seq = 26347 current_ts = 624.684509 current_received_ts = 624.684265 current_seq = 26348 count = 99 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.684509 last_received_ts = 624.684265 last_seq = 26348 current_ts = 624.701172 current_received_ts = 624.700684 current_seq = 26349 count = 100 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 624.701172 last_received_ts = 624.700684 last_seq = 26349 current_ts = 624.717834 current_received_ts = 624.717957 current_seq = 26350 count = 101 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 624.717834 last_received_ts = 624.717957 last_seq = 26350 current_ts = 624.734497 current_received_ts = 624.734253 current_seq = 26351 count = 102 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.734497 last_received_ts = 624.734253 last_seq = 26351 current_ts = 624.751160 current_received_ts = 624.750732 current_seq = 26352 count = 103 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.751160 last_received_ts = 624.750732 last_seq = 26352 current_ts = 624.767822 current_received_ts = 624.767517 current_seq = 26353 count = 104 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.767822 last_received_ts = 624.767517 last_seq = 26353 current_ts = 624.784485 current_received_ts = 624.783997 current_seq = 26354 count = 105 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.784485 last_received_ts = 624.783997 last_seq = 26354 current_ts = 624.801147 current_received_ts = 624.801147 current_seq = 26355 count = 106 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 624.801147 last_received_ts = 624.801147 last_seq = 26355 current_ts = 624.817810 current_received_ts = 624.817566 current_seq = 26356 count = 107 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.817810 last_received_ts = 624.817566 last_seq = 26356 current_ts = 624.834473 current_received_ts = 624.834900 current_seq = 26357 count = 108 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 624.834473 last_received_ts = 624.834900 last_seq = 26357 current_ts = 624.851135 current_received_ts = 624.850647 current_seq = 26358 count = 109 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.851135 last_received_ts = 624.850647 last_seq = 26358 current_ts = 624.867798 current_received_ts = 624.867493 current_seq = 26359 count = 110 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 624.867798 last_received_ts = 624.867493 last_seq = 26359 current_ts = 624.884460 current_received_ts = 624.883972 current_seq = 26360 count = 111 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 68us (kms_flip:2649) DEBUG: name = flip last_ts = 624.884460 last_received_ts = 624.883972 last_seq = 26360 current_ts = 624.901123 current_received_ts = 624.900757 current_seq = 26361 count = 112 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 624.901123 last_received_ts = 624.900757 last_seq = 26361 current_ts = 624.917786 current_received_ts = 624.917542 current_seq = 26362 count = 113 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 46us (kms_flip:2649) DEBUG: name = flip last_ts = 624.917786 last_received_ts = 624.917542 last_seq = 26362 current_ts = 624.934448 current_received_ts = 624.934265 current_seq = 26363 count = 114 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 26us (kms_flip:2649) DEBUG: name = flip last_ts = 624.934448 last_received_ts = 624.934265 last_seq = 26363 current_ts = 624.951111 current_received_ts = 624.950623 current_seq = 26364 count = 115 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.951111 last_received_ts = 624.950623 last_seq = 26364 current_ts = 624.967773 current_received_ts = 624.967468 current_seq = 26365 count = 116 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 624.967773 last_received_ts = 624.967468 last_seq = 26365 current_ts = 624.984436 current_received_ts = 624.984558 current_seq = 26366 count = 117 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 624.984436 last_received_ts = 624.984558 last_seq = 26366 current_ts = 625.001099 current_received_ts = 625.000732 current_seq = 26367 count = 118 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 625.001099 last_received_ts = 625.000732 last_seq = 26367 current_ts = 625.017761 current_received_ts = 625.017517 current_seq = 26368 count = 119 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.017761 last_received_ts = 625.017517 last_seq = 26368 current_ts = 625.034424 current_received_ts = 625.034973 current_seq = 26369 count = 120 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.034424 last_received_ts = 625.034973 last_seq = 26369 current_ts = 625.051086 current_received_ts = 625.050598 current_seq = 26370 count = 121 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.051086 last_received_ts = 625.050598 last_seq = 26370 current_ts = 625.067749 current_received_ts = 625.067444 current_seq = 26371 count = 122 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.067749 last_received_ts = 625.067444 last_seq = 26371 current_ts = 625.084412 current_received_ts = 625.084229 current_seq = 26372 count = 123 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.084412 last_received_ts = 625.084229 last_seq = 26372 current_ts = 625.101074 current_received_ts = 625.100586 current_seq = 26373 count = 124 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 625.101074 last_received_ts = 625.100586 last_seq = 26373 current_ts = 625.117737 current_received_ts = 625.117493 current_seq = 26374 count = 125 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.117737 last_received_ts = 625.117493 last_seq = 26374 current_ts = 625.134399 current_received_ts = 625.134644 current_seq = 26375 count = 126 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 20us (kms_flip:2649) DEBUG: name = flip last_ts = 625.134399 last_received_ts = 625.134644 last_seq = 26375 current_ts = 625.151062 current_received_ts = 625.151062 current_seq = 26376 count = 127 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 43us (kms_flip:2649) DEBUG: name = flip last_ts = 625.151062 last_received_ts = 625.151062 last_seq = 26376 current_ts = 625.167725 current_received_ts = 625.167847 current_seq = 26377 count = 128 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.167725 last_received_ts = 625.167847 last_seq = 26377 current_ts = 625.184387 current_received_ts = 625.184204 current_seq = 26378 count = 129 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.184387 last_received_ts = 625.184204 last_seq = 26378 current_ts = 625.201050 current_received_ts = 625.200806 current_seq = 26379 count = 130 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 625.201050 last_received_ts = 625.200806 last_seq = 26379 current_ts = 625.217712 current_received_ts = 625.217529 current_seq = 26380 count = 131 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.217712 last_received_ts = 625.217529 last_seq = 26380 current_ts = 625.234375 current_received_ts = 625.233887 current_seq = 26381 count = 132 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.234375 last_received_ts = 625.233887 last_seq = 26381 current_ts = 625.251038 current_received_ts = 625.250610 current_seq = 26382 count = 133 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 625.251038 last_received_ts = 625.250610 last_seq = 26382 current_ts = 625.267700 current_received_ts = 625.267578 current_seq = 26383 count = 134 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.267700 last_received_ts = 625.267578 last_seq = 26383 current_ts = 625.284363 current_received_ts = 625.284180 current_seq = 26384 count = 135 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.284363 last_received_ts = 625.284180 last_seq = 26384 current_ts = 625.301025 current_received_ts = 625.300476 current_seq = 26385 count = 136 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 625.301025 last_received_ts = 625.300476 last_seq = 26385 current_ts = 625.317688 current_received_ts = 625.317383 current_seq = 26386 count = 137 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.317688 last_received_ts = 625.317383 last_seq = 26386 current_ts = 625.334351 current_received_ts = 625.334167 current_seq = 26387 count = 138 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 25us (kms_flip:2649) DEBUG: name = flip last_ts = 625.334351 last_received_ts = 625.334167 last_seq = 26387 current_ts = 625.351013 current_received_ts = 625.350525 current_seq = 26388 count = 139 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.351013 last_received_ts = 625.350525 last_seq = 26388 current_ts = 625.367676 current_received_ts = 625.367493 current_seq = 26389 count = 140 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.367676 last_received_ts = 625.367493 last_seq = 26389 current_ts = 625.384338 current_received_ts = 625.383789 current_seq = 26390 count = 141 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.384338 last_received_ts = 625.383789 last_seq = 26390 current_ts = 625.401001 current_received_ts = 625.401001 current_seq = 26391 count = 142 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.401001 last_received_ts = 625.401001 last_seq = 26391 current_ts = 625.417664 current_received_ts = 625.417419 current_seq = 26392 count = 143 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.417664 last_received_ts = 625.417419 last_seq = 26392 current_ts = 625.434326 current_received_ts = 625.434875 current_seq = 26393 count = 144 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 19us (kms_flip:2649) DEBUG: name = flip last_ts = 625.434326 last_received_ts = 625.434875 last_seq = 26393 current_ts = 625.450989 current_received_ts = 625.450500 current_seq = 26394 count = 145 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.450989 last_received_ts = 625.450500 last_seq = 26394 current_ts = 625.467651 current_received_ts = 625.467468 current_seq = 26395 count = 146 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 625.467651 last_received_ts = 625.467468 last_seq = 26395 current_ts = 625.484314 current_received_ts = 625.484314 current_seq = 26396 count = 147 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.484314 last_received_ts = 625.484314 last_seq = 26396 current_ts = 625.500977 current_received_ts = 625.500488 current_seq = 26397 count = 148 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.500977 last_received_ts = 625.500488 last_seq = 26397 current_ts = 625.517639 current_received_ts = 625.517456 current_seq = 26398 count = 149 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 625.517639 last_received_ts = 625.517456 last_seq = 26398 current_ts = 625.534302 current_received_ts = 625.534607 current_seq = 26399 count = 150 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.534302 last_received_ts = 625.534607 last_seq = 26399 current_ts = 625.550964 current_received_ts = 625.550537 current_seq = 26400 count = 151 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.550964 last_received_ts = 625.550537 last_seq = 26400 current_ts = 625.567627 current_received_ts = 625.567444 current_seq = 26401 count = 152 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 625.567627 last_received_ts = 625.567444 last_seq = 26401 current_ts = 625.584290 current_received_ts = 625.584106 current_seq = 26402 count = 153 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.584290 last_received_ts = 625.584106 last_seq = 26402 current_ts = 625.600952 current_received_ts = 625.600525 current_seq = 26403 count = 154 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.600952 last_received_ts = 625.600525 last_seq = 26403 current_ts = 625.617615 current_received_ts = 625.617371 current_seq = 26404 count = 155 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 23us (kms_flip:2649) DEBUG: name = flip last_ts = 625.617615 last_received_ts = 625.617371 last_seq = 26404 current_ts = 625.634277 current_received_ts = 625.634155 current_seq = 26405 count = 156 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 20us (kms_flip:2649) DEBUG: name = flip last_ts = 625.634277 last_received_ts = 625.634155 last_seq = 26405 current_ts = 625.650940 current_received_ts = 625.650818 current_seq = 26406 count = 157 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.650940 last_received_ts = 625.650818 last_seq = 26406 current_ts = 625.667603 current_received_ts = 625.667419 current_seq = 26407 count = 158 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.667603 last_received_ts = 625.667419 last_seq = 26407 current_ts = 625.684265 current_received_ts = 625.684204 current_seq = 26408 count = 159 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.684265 last_received_ts = 625.684204 last_seq = 26408 current_ts = 625.700928 current_received_ts = 625.700500 current_seq = 26409 count = 160 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.700928 last_received_ts = 625.700500 last_seq = 26409 current_ts = 625.717590 current_received_ts = 625.717407 current_seq = 26410 count = 161 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.717590 last_received_ts = 625.717407 last_seq = 26410 current_ts = 625.734253 current_received_ts = 625.734131 current_seq = 26411 count = 162 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.734253 last_received_ts = 625.734131 last_seq = 26411 current_ts = 625.750916 current_received_ts = 625.750488 current_seq = 26412 count = 163 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.750916 last_received_ts = 625.750488 last_seq = 26412 current_ts = 625.767578 current_received_ts = 625.767761 current_seq = 26413 count = 164 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 22us (kms_flip:2649) DEBUG: name = flip last_ts = 625.767578 last_received_ts = 625.767761 last_seq = 26413 current_ts = 625.784241 current_received_ts = 625.784119 current_seq = 26414 count = 165 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 24us (kms_flip:2649) DEBUG: name = flip last_ts = 625.784241 last_received_ts = 625.784119 last_seq = 26414 current_ts = 625.800903 current_received_ts = 625.800476 current_seq = 26415 count = 166 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.800903 last_received_ts = 625.800476 last_seq = 26415 current_ts = 625.817566 current_received_ts = 625.817749 current_seq = 26416 count = 167 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 21us (kms_flip:2649) DEBUG: name = flip last_ts = 625.817566 last_received_ts = 625.817749 last_seq = 26416 current_ts = 625.834229 current_received_ts = 625.833801 current_seq = 26417 count = 168 seq_step = 1 (kms_flip:2649) DEBUG: Vblank took 1042us (kms_flip:2649) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:2649) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2649) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2649) igt_core-INFO: Stack trace: (kms_flip:2649) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2649) igt_core-INFO: #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() (kms_flip:2649) igt_core-INFO: #2 ../tests/kms_flip.c:1887 run_test() (kms_flip:2649) igt_core-INFO: #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2043() (kms_flip:2649) igt_core-INFO: #4 ../tests/kms_flip.c:2043 main() (kms_flip:2649) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2649) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2649) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A2: FAIL (3.450s)
Dmesg	<6> [636.985209] [IGT] kms_flip: starting dynamic subtest A-HDMI-A2 <7> [636.989511] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:179] <7> [636.989868] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:181] <7> [637.028216] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:77:pipe A] <7> [637.028676] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:120:pipe B] <7> [637.029977] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:163:pipe C] <7> [637.030153] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.enable (expected yes, found no) <7> [637.030672] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.active (expected yes, found no) <7> [637.032751] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1) <7> [637.034030] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in lane_count (expected 4, found 0) <7> [637.034419] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000) <7> [637.034809] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [637.035472] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [637.035853] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [637.036424] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [637.036802] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [637.037379] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [637.037772] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [637.038347] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [637.038729] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [637.039281] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [637.039660] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [637.041966] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [637.042469] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [637.042863] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [637.044219] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [637.044609] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [637.045215] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [637.045596] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [637.046179] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [637.046567] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [637.047199] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [637.047587] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [637.049971] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [637.050489] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [637.050869] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [637.052087] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [637.052478] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [637.052857] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [637.053458] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [637.053849] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in has_hdmi_sink (expected yes, found no) <7> [637.054453] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in has_infoframe (expected yes, found no) <7> [637.054836] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [637.055390] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [637.055771] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [637.056390] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in port_clock (expected 148500, found 0) <7> [637.056787] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000) <7> [637.059572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in avi infoframe <7> [637.060337] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [637.060720] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [637.060725] i915 0000:00:02.0: colorspace: RGB <7> [637.060730] i915 0000:00:02.0: scan mode: Underscan <7> [637.060733] i915 0000:00:02.0: colorimetry: No Data <7> [637.060736] i915 0000:00:02.0: picture aspect: 16:9 <7> [637.060740] i915 0000:00:02.0: active aspect: Same as Picture <7> [637.060743] i915 0000:00:02.0: itc: No Data <7> [637.060747] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [637.060750] i915 0000:00:02.0: quantization range: Default <7> [637.060753] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [637.060757] i915 0000:00:02.0: video code: 16 <7> [637.060760] i915 0000:00:02.0: ycc quantization range: Full <7> [637.060764] i915 0000:00:02.0: hdmi content type: Graphics <7> [637.060767] i915 0000:00:02.0: pixel repeat: 0 <7> [637.060770] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [637.060774] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [637.061806] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in spd infoframe <7> [637.062401] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [637.062779] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [637.062784] i915 0000:00:02.0: vendor: Intel <7> [637.062787] i915 0000:00:02.0: product: Integrated gfx <7> [637.062790] i915 0000:00:02.0: source device information: PC General (0x9) <7> [637.062794] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [637.063369] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:163:pipe C] fastset requirement not met in hdmi infoframe <7> [637.063750] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [637.066009] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [637.066016] i915 0000:00:02.0: empty frame <7> [637.066019] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [637.066535] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:163:pipe C] fastset requirement not met, forcing full modeset <7> [637.068145] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:163:pipe C] releasing PORT PLL B <7> [637.068607] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:163:pipe C] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x4 -> 0x0 <7> [637.069562] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:157:cursor C] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0 <7> [637.070300] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:163:pipe C] min cdclk: 192000 kHz -> 0 kHz <7> [637.070747] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [637.071329] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz <7> [637.071718] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4 <7> [637.072341] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:163:pipe C] enable: no [modeset] <7> [637.072724] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:121:plane 1C] fb: [NOFB], visible: no <7> [637.074681] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:130:plane 2C] fb: [NOFB], visible: no <7> [637.075975] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:139:plane 3C] fb: [NOFB], visible: no <7> [637.076366] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:148:plane 4C] fb: [NOFB], visible: no <7> [637.076766] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:157:cursor C] fb: [NOFB], visible: no <7> [637.078102] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:165:HDMI-A-1][ENCODER:164:DDI B/PHY B] Disable audio codec on [CRTC:163:pipe C] <7> [637.096508] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port B <7> [637.099130] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe C <7> [637.109485] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10 <7> [637.114003] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time <7> [637.220460] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B <7> [637.221579] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL B (active 0x4, on? 1) for [CRTC:163:pipe C] <7> [637.225020] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL B <7> [637.225580] 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> [637.226281] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B] <7> [637.226717] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:174:DDI C/PHY C] <7> [637.227489] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:165:HDMI-A-1] <7> [637.228385] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-b <7> [637.228844] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:163:pipe C] <7> [637.230327] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [637.230744] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz <7> [637.231141] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13 <7> [637.231622] 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> [637.234190] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:77:pipe A] <7> [637.234273] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:175:HDMI-A-2] <7> [637.234488] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:175:HDMI-A-2] Limiting target display pipe bpp to 30 (EDID bpp 48, max requested bpp 30, max platform bpp 36) <7> [637.235282] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24) <7> [637.235677] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:77:pipe A] hw max bpp: 30, pipe bpp: 24, dithering: 0 <7> [637.237313] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:174:DDI C/PHY C] [CRTC:77:pipe A] <7> [637.237710] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [637.238426] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL <7> [637.238443] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled <7> [637.238855] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [637.239504] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [637.239886] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [637.240449] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d) <7> [637.240834] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [637.241434] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [637.241824] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [637.243811] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [637.244617] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [637.245694] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [637.246762] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [637.247633] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [637.248308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [637.248692] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [637.249267] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [637.249647] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [637.250258] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [637.250639] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [637.253266] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [637.253767] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [637.254554] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [637.255127] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [637.255508] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [637.255886] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [637.256706] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [637.257408] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [637.257799] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [637.258373] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [637.258757] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [637.259371] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [637.259751] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [637.262027] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [637.262526] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [637.262904] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [637.264417] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in has_infoframe (expected no, found yes) <7> [637.264827] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [637.265802] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [637.266495] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [637.266881] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in port_clock (expected 0, found 148500) <7> [637.267474] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [637.267855] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in avi infoframe <7> [637.268427] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [637.268806] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [637.271014] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [637.271021] i915 0000:00:02.0: colorspace: RGB <7> [637.271025] i915 0000:00:02.0: scan mode: Underscan <7> [637.271028] i915 0000:00:02.0: colorimetry: No Data <7> [637.271032] i915 0000:00:02.0: picture aspect: 16:9 <7> [637.271035] i915 0000:00:02.0: active aspect: Same as Picture <7> [637.271039] i915 0000:00:02.0: itc: No Data <7> [637.271042] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [637.271045] i915 0000:00:02.0: quantization range: Default <7> [637.271049] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [637.271052] i915 0000:00:02.0: video code: 16 <7> [637.271056] i915 0000:00:02.0: ycc quantization range: Full <7> [637.271059] i915 0000:00:02.0: hdmi content type: Graphics <7> [637.271062] i915 0000:00:02.0: pixel repeat: 0 <7> [637.271066] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [637.271071] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in spd infoframe <7> [637.271573] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [637.272324] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [637.272710] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [637.272714] i915 0000:00:02.0: vendor: Intel <7> [637.272718] i915 0000:00:02.0: product: Integrated gfx <7> [637.272721] i915 0000:00:02.0: source device information: PC General (0x9) <7> [637.272726] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hdmi infoframe <7> [637.273769] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [637.274530] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [637.274909] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [637.274914] i915 0000:00:02.0: empty frame <7> [637.274920] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:77:pipe A] fastset requirement not met, forcing full modeset <7> [637.275655] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:77:pipe A] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x1 <7> [637.276281] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988 <7> [637.276658] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:71:cursor A] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32 <7> [637.277197] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [637.277572] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0 <7> [637.277943] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0 <7> [637.279864] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0 <7> [637.280734] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:77:pipe A] min cdclk: 0 kHz -> 192000 kHz <7> [637.282055] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:77:pipe A] using pre-allocated PORT PLL C <7> [637.282448] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:77:pipe A] reserving PORT PLL C <7> [637.282838] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:77:pipe A] enable: yes [modeset] <7> [637.284189] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [637.284581] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0 <7> [637.285697] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [637.286354] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [637.286736] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [637.287280] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [637.287660] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [637.288213] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x0 <7> [637.288590] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [637.288595] i915 0000:00:02.0: colorspace: RGB <7> [637.288599] i915 0000:00:02.0: scan mode: Underscan <7> [637.288603] i915 0000:00:02.0: colorimetry: No Data <7> [637.288606] i915 0000:00:02.0: picture aspect: 16:9 <7> [637.288610] i915 0000:00:02.0: active aspect: Same as Picture <7> [637.288613] i915 0000:00:02.0: itc: No Data <7> [637.288616] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [637.288620] i915 0000:00:02.0: quantization range: Default <7> [637.288623] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [637.288626] i915 0000:00:02.0: video code: 16 <7> [637.288630] i915 0000:00:02.0: ycc quantization range: Full <7> [637.288633] i915 0000:00:02.0: hdmi content type: Graphics <7> [637.288636] i915 0000:00:02.0: pixel repeat: 0 <7> [637.288639] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [637.288643] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [637.288647] i915 0000:00:02.0: vendor: Intel <7> [637.288650] i915 0000:00:02.0: product: Integrated gfx <7> [637.288654] i915 0000:00:02.0: source device information: PC General (0x9) <7> [637.288657] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [637.288661] i915 0000:00:02.0: empty frame <7> [637.288665] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 08 00 65 32 00 01 00 00 00 00 00 00 00 00 <7> [637.291017] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 4d 69 20 54 56 09 07 07 11 17 50 51 <7> [637.291522] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 07 00 00 00 <7> [637.291898] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [637.293002] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [637.293387] 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> [637.293764] 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> [637.294834] 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> [637.295833] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [637.296478] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [637.296861] 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=1084-1089 vt=1125, flags=0x5 <7> [637.297419] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 <7> [637.297798] 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=1084-1089 vt=1125, flags=0x5 <7> [637.298374] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000 <7> [637.298751] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0 <7> [637.300699] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [637.302314] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [637.302710] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [637.303650] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6300, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d <7> [637.304314] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [637.304703] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [637.305263] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [637.305643] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [637.306216] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [637.306593] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [637.308468] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [637.309247] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [637.309643] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:179] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [637.311169] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [637.311565] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [637.311942] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:44:plane 2A] fb: [NOFB], visible: no <7> [637.312940] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:plane 3A] fb: [NOFB], visible: no <7> [637.313617] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:62:plane 4A] fb: [NOFB], visible: no <7> [637.314200] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:71:cursor A] fb: [NOFB], visible: no <7> [637.315469] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c <7> [637.318365] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B] <7> [637.318859] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:174:DDI C/PHY C] <7> [637.319828] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x1, on? 0) for [CRTC:77:pipe A] <7> [637.320483] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C <7> [637.321205] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C <7> [637.321695] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [637.324574] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 16588800 bytes of contiguous stolen space for FBC, limit: 1 <7> [637.325092] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A] <7> [637.341339] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:175:HDMI-A-2][ENCODER:174:DDI C/PHY C] Enable audio codec on [CRTC:77:pipe A], 36 bytes ELD <7> [637.357965] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000) <7> [637.358479] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N <7> [637.360471] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:175:HDMI-A-2] <7> [637.361401] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:77:pipe A] <6> [640.440974] [IGT] kms_flip: finished subtest A-HDMI-A2, FAIL

Detail

Value

Duration

3.45 seconds

Hostname

shard-glk8

Igt-Version

IGT-Version: 2.3-g23fdc238d (x86_64) (Linux: 7.0.0-rc3-CI_DRM_18143-g45618ec6cfed+ x86_64)

Out

Starting dynamic subtest: A-HDMI-A2
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A2: FAIL (3.450s)

Err

Starting dynamic subtest: A-HDMI-A2
(kms_flip:2649) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:2649) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2649) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.818054
last_received_ts = 623.817566
last_seq = 26296
current_ts = 623.834656
current_received_ts = 623.834290
current_seq = 26297
count = 48
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.834656
last_received_ts = 623.834290
last_seq = 26297
current_ts = 623.851379
current_received_ts = 623.850830
current_seq = 26298
count = 49
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.851379
last_received_ts = 623.850830
last_seq = 26298
current_ts = 623.868042
current_received_ts = 623.867676
current_seq = 26299
count = 50
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.868042
last_received_ts = 623.867676
last_seq = 26299
current_ts = 623.884705
current_received_ts = 623.884521
current_seq = 26300
count = 51
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.884705
last_received_ts = 623.884521
last_seq = 26300
current_ts = 623.901306
current_received_ts = 623.901184
current_seq = 26301
count = 52
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.901306
last_received_ts = 623.901184
last_seq = 26301
current_ts = 623.918030
current_received_ts = 623.917542
current_seq = 26302
count = 53
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.918030
last_received_ts = 623.917542
last_seq = 26302
current_ts = 623.934631
current_received_ts = 623.934448
current_seq = 26303
count = 54
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.934631
last_received_ts = 623.934448
last_seq = 26303
current_ts = 623.951355
current_received_ts = 623.950806
current_seq = 26304
count = 55
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.951355
last_received_ts = 623.950806
last_seq = 26304
current_ts = 623.968018
current_received_ts = 623.967590
current_seq = 26305
count = 56
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.968018
last_received_ts = 623.967590
last_seq = 26305
current_ts = 623.984680
current_received_ts = 623.984436
current_seq = 26306
count = 57
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 623.984680
last_received_ts = 623.984436
last_seq = 26306
current_ts = 624.001282
current_received_ts = 624.001099
current_seq = 26307
count = 58
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.001282
last_received_ts = 624.001099
last_seq = 26307
current_ts = 624.018005
current_received_ts = 624.017578
current_seq = 26308
count = 59
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.018005
last_received_ts = 624.017578
last_seq = 26308
current_ts = 624.034668
current_received_ts = 624.034729
current_seq = 26309
count = 60
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.034668
last_received_ts = 624.034729
last_seq = 26309
current_ts = 624.051270
current_received_ts = 624.051147
current_seq = 26310
count = 61
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.051270
last_received_ts = 624.051147
last_seq = 26310
current_ts = 624.067993
current_received_ts = 624.067566
current_seq = 26311
count = 62
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.067993
last_received_ts = 624.067566
last_seq = 26311
current_ts = 624.084595
current_received_ts = 624.084717
current_seq = 26312
count = 63
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.084595
last_received_ts = 624.084717
last_seq = 26312
current_ts = 624.101318
current_received_ts = 624.101196
current_seq = 26313
count = 64
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.101318
last_received_ts = 624.101196
last_seq = 26313
current_ts = 624.117981
current_received_ts = 624.117859
current_seq = 26314
count = 65
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.117981
last_received_ts = 624.117859
last_seq = 26314
current_ts = 624.134644
current_received_ts = 624.134460
current_seq = 26315
count = 66
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.134644
last_received_ts = 624.134460
last_seq = 26315
current_ts = 624.151306
current_received_ts = 624.150818
current_seq = 26316
count = 67
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.151306
last_received_ts = 624.150818
last_seq = 26316
current_ts = 624.167908
current_received_ts = 624.167542
current_seq = 26317
count = 68
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.167908
last_received_ts = 624.167542
last_seq = 26317
current_ts = 624.184631
current_received_ts = 624.184448
current_seq = 26318
count = 69
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.184631
last_received_ts = 624.184448
last_seq = 26318
current_ts = 624.201294
current_received_ts = 624.201111
current_seq = 26319
count = 70
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.201294
last_received_ts = 624.201111
last_seq = 26319
current_ts = 624.217896
current_received_ts = 624.217529
current_seq = 26320
count = 71
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.217896
last_received_ts = 624.217529
last_seq = 26320
current_ts = 624.234619
current_received_ts = 624.234863
current_seq = 26321
count = 72
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.234619
last_received_ts = 624.234863
last_seq = 26321
current_ts = 624.251282
current_received_ts = 624.250732
current_seq = 26322
count = 73
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 20us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.251282
last_received_ts = 624.250732
last_seq = 26322
current_ts = 624.267944
current_received_ts = 624.267517
current_seq = 26323
count = 74
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.267944
last_received_ts = 624.267517
last_seq = 26323
current_ts = 624.284607
current_received_ts = 624.284424
current_seq = 26324
count = 75
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.284607
last_received_ts = 624.284424
last_seq = 26324
current_ts = 624.301270
current_received_ts = 624.301086
current_seq = 26325
count = 76
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.301270
last_received_ts = 624.301086
last_seq = 26325
current_ts = 624.317932
current_received_ts = 624.317383
current_seq = 26326
count = 77
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.317932
last_received_ts = 624.317383
last_seq = 26326
current_ts = 624.334595
current_received_ts = 624.334473
current_seq = 26327
count = 78
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.334595
last_received_ts = 624.334473
last_seq = 26327
current_ts = 624.351257
current_received_ts = 624.350830
current_seq = 26328
count = 79
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.351257
last_received_ts = 624.350830
last_seq = 26328
current_ts = 624.367920
current_received_ts = 624.367859
current_seq = 26329
count = 80
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.367920
last_received_ts = 624.367859
last_seq = 26329
current_ts = 624.384583
current_received_ts = 624.384460
current_seq = 26330
count = 81
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.384583
last_received_ts = 624.384460
last_seq = 26330
current_ts = 624.401245
current_received_ts = 624.400696
current_seq = 26331
count = 82
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.401245
last_received_ts = 624.400696
last_seq = 26331
current_ts = 624.417908
current_received_ts = 624.417480
current_seq = 26332
count = 83
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.417908
last_received_ts = 624.417480
last_seq = 26332
current_ts = 624.434570
current_received_ts = 624.434692
current_seq = 26333
count = 84
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.434570
last_received_ts = 624.434692
last_seq = 26333
current_ts = 624.451233
current_received_ts = 624.450867
current_seq = 26334
count = 85
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.451233
last_received_ts = 624.450867
last_seq = 26334
current_ts = 624.467896
current_received_ts = 624.467896
current_seq = 26335
count = 86
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.467896
last_received_ts = 624.467896
last_seq = 26335
current_ts = 624.484558
current_received_ts = 624.484131
current_seq = 26336
count = 87
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.484558
last_received_ts = 624.484131
last_seq = 26336
current_ts = 624.501221
current_received_ts = 624.500732
current_seq = 26337
count = 88
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.501221
last_received_ts = 624.500732
last_seq = 26337
current_ts = 624.517883
current_received_ts = 624.517456
current_seq = 26338
count = 89
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.517883
last_received_ts = 624.517456
last_seq = 26338
current_ts = 624.534546
current_received_ts = 624.534363
current_seq = 26339
count = 90
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.534546
last_received_ts = 624.534363
last_seq = 26339
current_ts = 624.551208
current_received_ts = 624.550720
current_seq = 26340
count = 91
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.551208
last_received_ts = 624.550720
last_seq = 26340
current_ts = 624.567871
current_received_ts = 624.567505
current_seq = 26341
count = 92
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.567871
last_received_ts = 624.567505
last_seq = 26341
current_ts = 624.584534
current_received_ts = 624.584045
current_seq = 26342
count = 93
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.584534
last_received_ts = 624.584045
last_seq = 26342
current_ts = 624.601196
current_received_ts = 624.601501
current_seq = 26343
count = 94
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 20us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.601196
last_received_ts = 624.601501
last_seq = 26343
current_ts = 624.617859
current_received_ts = 624.617920
current_seq = 26344
count = 95
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.617859
last_received_ts = 624.617920
last_seq = 26344
current_ts = 624.634521
current_received_ts = 624.634338
current_seq = 26345
count = 96
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.634521
last_received_ts = 624.634338
last_seq = 26345
current_ts = 624.651184
current_received_ts = 624.650818
current_seq = 26346
count = 97
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.651184
last_received_ts = 624.650818
last_seq = 26346
current_ts = 624.667847
current_received_ts = 624.667908
current_seq = 26347
count = 98
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 61us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.667847
last_received_ts = 624.667908
last_seq = 26347
current_ts = 624.684509
current_received_ts = 624.684265
current_seq = 26348
count = 99
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.684509
last_received_ts = 624.684265
last_seq = 26348
current_ts = 624.701172
current_received_ts = 624.700684
current_seq = 26349
count = 100
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.701172
last_received_ts = 624.700684
last_seq = 26349
current_ts = 624.717834
current_received_ts = 624.717957
current_seq = 26350
count = 101
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.717834
last_received_ts = 624.717957
last_seq = 26350
current_ts = 624.734497
current_received_ts = 624.734253
current_seq = 26351
count = 102
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.734497
last_received_ts = 624.734253
last_seq = 26351
current_ts = 624.751160
current_received_ts = 624.750732
current_seq = 26352
count = 103
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.751160
last_received_ts = 624.750732
last_seq = 26352
current_ts = 624.767822
current_received_ts = 624.767517
current_seq = 26353
count = 104
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.767822
last_received_ts = 624.767517
last_seq = 26353
current_ts = 624.784485
current_received_ts = 624.783997
current_seq = 26354
count = 105
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.784485
last_received_ts = 624.783997
last_seq = 26354
current_ts = 624.801147
current_received_ts = 624.801147
current_seq = 26355
count = 106
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.801147
last_received_ts = 624.801147
last_seq = 26355
current_ts = 624.817810
current_received_ts = 624.817566
current_seq = 26356
count = 107
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.817810
last_received_ts = 624.817566
last_seq = 26356
current_ts = 624.834473
current_received_ts = 624.834900
current_seq = 26357
count = 108
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.834473
last_received_ts = 624.834900
last_seq = 26357
current_ts = 624.851135
current_received_ts = 624.850647
current_seq = 26358
count = 109
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.851135
last_received_ts = 624.850647
last_seq = 26358
current_ts = 624.867798
current_received_ts = 624.867493
current_seq = 26359
count = 110
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.867798
last_received_ts = 624.867493
last_seq = 26359
current_ts = 624.884460
current_received_ts = 624.883972
current_seq = 26360
count = 111
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 68us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.884460
last_received_ts = 624.883972
last_seq = 26360
current_ts = 624.901123
current_received_ts = 624.900757
current_seq = 26361
count = 112
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.901123
last_received_ts = 624.900757
last_seq = 26361
current_ts = 624.917786
current_received_ts = 624.917542
current_seq = 26362
count = 113
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 46us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.917786
last_received_ts = 624.917542
last_seq = 26362
current_ts = 624.934448
current_received_ts = 624.934265
current_seq = 26363
count = 114
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 26us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.934448
last_received_ts = 624.934265
last_seq = 26363
current_ts = 624.951111
current_received_ts = 624.950623
current_seq = 26364
count = 115
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.951111
last_received_ts = 624.950623
last_seq = 26364
current_ts = 624.967773
current_received_ts = 624.967468
current_seq = 26365
count = 116
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.967773
last_received_ts = 624.967468
last_seq = 26365
current_ts = 624.984436
current_received_ts = 624.984558
current_seq = 26366
count = 117
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 624.984436
last_received_ts = 624.984558
last_seq = 26366
current_ts = 625.001099
current_received_ts = 625.000732
current_seq = 26367
count = 118
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.001099
last_received_ts = 625.000732
last_seq = 26367
current_ts = 625.017761
current_received_ts = 625.017517
current_seq = 26368
count = 119
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.017761
last_received_ts = 625.017517
last_seq = 26368
current_ts = 625.034424
current_received_ts = 625.034973
current_seq = 26369
count = 120
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.034424
last_received_ts = 625.034973
last_seq = 26369
current_ts = 625.051086
current_received_ts = 625.050598
current_seq = 26370
count = 121
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.051086
last_received_ts = 625.050598
last_seq = 26370
current_ts = 625.067749
current_received_ts = 625.067444
current_seq = 26371
count = 122
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.067749
last_received_ts = 625.067444
last_seq = 26371
current_ts = 625.084412
current_received_ts = 625.084229
current_seq = 26372
count = 123
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.084412
last_received_ts = 625.084229
last_seq = 26372
current_ts = 625.101074
current_received_ts = 625.100586
current_seq = 26373
count = 124
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.101074
last_received_ts = 625.100586
last_seq = 26373
current_ts = 625.117737
current_received_ts = 625.117493
current_seq = 26374
count = 125
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.117737
last_received_ts = 625.117493
last_seq = 26374
current_ts = 625.134399
current_received_ts = 625.134644
current_seq = 26375
count = 126
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 20us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.134399
last_received_ts = 625.134644
last_seq = 26375
current_ts = 625.151062
current_received_ts = 625.151062
current_seq = 26376
count = 127
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 43us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.151062
last_received_ts = 625.151062
last_seq = 26376
current_ts = 625.167725
current_received_ts = 625.167847
current_seq = 26377
count = 128
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.167725
last_received_ts = 625.167847
last_seq = 26377
current_ts = 625.184387
current_received_ts = 625.184204
current_seq = 26378
count = 129
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.184387
last_received_ts = 625.184204
last_seq = 26378
current_ts = 625.201050
current_received_ts = 625.200806
current_seq = 26379
count = 130
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.201050
last_received_ts = 625.200806
last_seq = 26379
current_ts = 625.217712
current_received_ts = 625.217529
current_seq = 26380
count = 131
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.217712
last_received_ts = 625.217529
last_seq = 26380
current_ts = 625.234375
current_received_ts = 625.233887
current_seq = 26381
count = 132
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.234375
last_received_ts = 625.233887
last_seq = 26381
current_ts = 625.251038
current_received_ts = 625.250610
current_seq = 26382
count = 133
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.251038
last_received_ts = 625.250610
last_seq = 26382
current_ts = 625.267700
current_received_ts = 625.267578
current_seq = 26383
count = 134
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.267700
last_received_ts = 625.267578
last_seq = 26383
current_ts = 625.284363
current_received_ts = 625.284180
current_seq = 26384
count = 135
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.284363
last_received_ts = 625.284180
last_seq = 26384
current_ts = 625.301025
current_received_ts = 625.300476
current_seq = 26385
count = 136
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.301025
last_received_ts = 625.300476
last_seq = 26385
current_ts = 625.317688
current_received_ts = 625.317383
current_seq = 26386
count = 137
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.317688
last_received_ts = 625.317383
last_seq = 26386
current_ts = 625.334351
current_received_ts = 625.334167
current_seq = 26387
count = 138
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 25us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.334351
last_received_ts = 625.334167
last_seq = 26387
current_ts = 625.351013
current_received_ts = 625.350525
current_seq = 26388
count = 139
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.351013
last_received_ts = 625.350525
last_seq = 26388
current_ts = 625.367676
current_received_ts = 625.367493
current_seq = 26389
count = 140
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.367676
last_received_ts = 625.367493
last_seq = 26389
current_ts = 625.384338
current_received_ts = 625.383789
current_seq = 26390
count = 141
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.384338
last_received_ts = 625.383789
last_seq = 26390
current_ts = 625.401001
current_received_ts = 625.401001
current_seq = 26391
count = 142
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.401001
last_received_ts = 625.401001
last_seq = 26391
current_ts = 625.417664
current_received_ts = 625.417419
current_seq = 26392
count = 143
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.417664
last_received_ts = 625.417419
last_seq = 26392
current_ts = 625.434326
current_received_ts = 625.434875
current_seq = 26393
count = 144
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 19us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.434326
last_received_ts = 625.434875
last_seq = 26393
current_ts = 625.450989
current_received_ts = 625.450500
current_seq = 26394
count = 145
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.450989
last_received_ts = 625.450500
last_seq = 26394
current_ts = 625.467651
current_received_ts = 625.467468
current_seq = 26395
count = 146
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.467651
last_received_ts = 625.467468
last_seq = 26395
current_ts = 625.484314
current_received_ts = 625.484314
current_seq = 26396
count = 147
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.484314
last_received_ts = 625.484314
last_seq = 26396
current_ts = 625.500977
current_received_ts = 625.500488
current_seq = 26397
count = 148
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.500977
last_received_ts = 625.500488
last_seq = 26397
current_ts = 625.517639
current_received_ts = 625.517456
current_seq = 26398
count = 149
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.517639
last_received_ts = 625.517456
last_seq = 26398
current_ts = 625.534302
current_received_ts = 625.534607
current_seq = 26399
count = 150
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.534302
last_received_ts = 625.534607
last_seq = 26399
current_ts = 625.550964
current_received_ts = 625.550537
current_seq = 26400
count = 151
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.550964
last_received_ts = 625.550537
last_seq = 26400
current_ts = 625.567627
current_received_ts = 625.567444
current_seq = 26401
count = 152
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.567627
last_received_ts = 625.567444
last_seq = 26401
current_ts = 625.584290
current_received_ts = 625.584106
current_seq = 26402
count = 153
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.584290
last_received_ts = 625.584106
last_seq = 26402
current_ts = 625.600952
current_received_ts = 625.600525
current_seq = 26403
count = 154
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.600952
last_received_ts = 625.600525
last_seq = 26403
current_ts = 625.617615
current_received_ts = 625.617371
current_seq = 26404
count = 155
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 23us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.617615
last_received_ts = 625.617371
last_seq = 26404
current_ts = 625.634277
current_received_ts = 625.634155
current_seq = 26405
count = 156
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 20us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.634277
last_received_ts = 625.634155
last_seq = 26405
current_ts = 625.650940
current_received_ts = 625.650818
current_seq = 26406
count = 157
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.650940
last_received_ts = 625.650818
last_seq = 26406
current_ts = 625.667603
current_received_ts = 625.667419
current_seq = 26407
count = 158
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.667603
last_received_ts = 625.667419
last_seq = 26407
current_ts = 625.684265
current_received_ts = 625.684204
current_seq = 26408
count = 159
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.684265
last_received_ts = 625.684204
last_seq = 26408
current_ts = 625.700928
current_received_ts = 625.700500
current_seq = 26409
count = 160
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.700928
last_received_ts = 625.700500
last_seq = 26409
current_ts = 625.717590
current_received_ts = 625.717407
current_seq = 26410
count = 161
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.717590
last_received_ts = 625.717407
last_seq = 26410
current_ts = 625.734253
current_received_ts = 625.734131
current_seq = 26411
count = 162
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.734253
last_received_ts = 625.734131
last_seq = 26411
current_ts = 625.750916
current_received_ts = 625.750488
current_seq = 26412
count = 163
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.750916
last_received_ts = 625.750488
last_seq = 26412
current_ts = 625.767578
current_received_ts = 625.767761
current_seq = 26413
count = 164
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 22us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.767578
last_received_ts = 625.767761
last_seq = 26413
current_ts = 625.784241
current_received_ts = 625.784119
current_seq = 26414
count = 165
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 24us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.784241
last_received_ts = 625.784119
last_seq = 26414
current_ts = 625.800903
current_received_ts = 625.800476
current_seq = 26415
count = 166
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.800903
last_received_ts = 625.800476
last_seq = 26415
current_ts = 625.817566
current_received_ts = 625.817749
current_seq = 26416
count = 167
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 21us
(kms_flip:2649) DEBUG: name = flip
last_ts = 625.817566
last_received_ts = 625.817749
last_seq = 26416
current_ts = 625.834229
current_received_ts = 625.833801
current_seq = 26417
count = 168
seq_step = 1
(kms_flip:2649) DEBUG: Vblank took 1042us
(kms_flip:2649) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:2649) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2649) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2649) igt_core-INFO: Stack trace:
(kms_flip:2649) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2649) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:2649) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:2649) igt_core-INFO:   #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2043()
(kms_flip:2649) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:2649) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2649) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2649) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A2: FAIL (3.450s)

Dmesg

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

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

<7> [636.989868] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:181]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [637.060736] i915 0000:00:02.0: picture aspect: 16:9

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

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

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

<7> [637.060750] i915 0000:00:02.0: quantization range: Default

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

<7> [637.060757] i915 0000:00:02.0: video code: 16

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [637.225580] 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> [637.226281] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B]

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

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

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

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

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

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

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

<7> [637.231622] 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> [637.234190] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:77:pipe A]

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

<7> [637.234488] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:175:HDMI-A-2] Limiting target display pipe bpp to 30 (EDID bpp 48, max requested bpp 30, max platform bpp 36)

<7> [637.235282] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [637.271032] i915 0000:00:02.0: picture aspect: 16:9

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

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

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

<7> [637.271045] i915 0000:00:02.0: quantization range: Default

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

<7> [637.271052] i915 0000:00:02.0: video code: 16

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [637.277572] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [637.288213] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x0

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

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

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

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

<7> [637.288606] i915 0000:00:02.0: picture aspect: 16:9

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

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

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

<7> [637.288620] i915 0000:00:02.0: quantization range: Default

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

<7> [637.288626] i915 0000:00:02.0: video code: 16

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

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

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

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

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

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

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

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

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

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

<7> [637.288665] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 08 00 65 32 00 01 00 00 00 00 00 00 00 00

<7> [637.291017] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 4d 69 20 54 56 09 07 07 11 17 50 51

<7> [637.291522] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 07 00 00 00

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

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

<7> [637.293387] 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> [637.293764] 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> [637.294834] 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> [637.295833] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [637.296478] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [637.296861] 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=1084-1089 vt=1125, flags=0x5

<7> [637.297419] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5

<7> [637.297798] 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=1084-1089 vt=1125, flags=0x5

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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