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

Detail	Value
Duration	4.18 seconds
Hostname	shard-glk6
Igt-Version	IGT-Version: 2.3-g246d93c1d (x86_64) (Linux: 7.0.0-rc3-CI_DRM_18142-g4082c266f293+ x86_64)
Out	Starting dynamic subtest: B-HDMI-A2 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1887 run_test() #3 ../tests/kms_flip.c:2122 __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 B-HDMI-A2: FAIL (4.182s)
Err	Starting dynamic subtest: B-HDMI-A2 (kms_flip:2807) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:2807) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest B-HDMI-A2 failed. ** DEBUG (kms_flip:2807) DEBUG: name = flip last_ts = 553.563477 last_received_ts = 553.563232 last_seq = 20477 current_ts = 553.580139 current_received_ts = 553.579895 current_seq = 20478 count = 63 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.580139 last_received_ts = 553.579895 last_seq = 20478 current_ts = 553.596863 current_received_ts = 553.596558 current_seq = 20479 count = 64 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 553.596863 last_received_ts = 553.596558 last_seq = 20479 current_ts = 553.613525 current_received_ts = 553.613281 current_seq = 20480 count = 65 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 553.613525 last_received_ts = 553.613281 last_seq = 20480 current_ts = 553.630188 current_received_ts = 553.629883 current_seq = 20481 count = 66 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.630188 last_received_ts = 553.629883 last_seq = 20481 current_ts = 553.646851 current_received_ts = 553.646545 current_seq = 20482 count = 67 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.646851 last_received_ts = 553.646545 last_seq = 20482 current_ts = 553.663513 current_received_ts = 553.663269 current_seq = 20483 count = 68 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.663513 last_received_ts = 553.663269 last_seq = 20483 current_ts = 553.680176 current_received_ts = 553.679932 current_seq = 20484 count = 69 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.680176 last_received_ts = 553.679932 last_seq = 20484 current_ts = 553.696838 current_received_ts = 553.696411 current_seq = 20485 count = 70 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 553.696838 last_received_ts = 553.696411 last_seq = 20485 current_ts = 553.713562 current_received_ts = 553.713257 current_seq = 20486 count = 71 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 553.713562 last_received_ts = 553.713257 last_seq = 20486 current_ts = 553.730225 current_received_ts = 553.729919 current_seq = 20487 count = 72 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 553.730225 last_received_ts = 553.729919 last_seq = 20487 current_ts = 553.746887 current_received_ts = 553.746643 current_seq = 20488 count = 73 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 553.746887 last_received_ts = 553.746643 last_seq = 20488 current_ts = 553.763550 current_received_ts = 553.763306 current_seq = 20489 count = 74 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 553.763550 last_received_ts = 553.763306 last_seq = 20489 current_ts = 553.780212 current_received_ts = 553.779907 current_seq = 20490 count = 75 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.780212 last_received_ts = 553.779907 last_seq = 20490 current_ts = 553.796875 current_received_ts = 553.796631 current_seq = 20491 count = 76 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 553.796875 last_received_ts = 553.796631 last_seq = 20491 current_ts = 553.813538 current_received_ts = 553.813293 current_seq = 20492 count = 77 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.813538 last_received_ts = 553.813293 last_seq = 20492 current_ts = 553.830261 current_received_ts = 553.829956 current_seq = 20493 count = 78 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.830261 last_received_ts = 553.829956 last_seq = 20493 current_ts = 553.846924 current_received_ts = 553.846619 current_seq = 20494 count = 79 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.846924 last_received_ts = 553.846619 last_seq = 20494 current_ts = 553.863586 current_received_ts = 553.863342 current_seq = 20495 count = 80 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.863586 last_received_ts = 553.863342 last_seq = 20495 current_ts = 553.880249 current_received_ts = 553.880005 current_seq = 20496 count = 81 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.880249 last_received_ts = 553.880005 last_seq = 20496 current_ts = 553.896912 current_received_ts = 553.896667 current_seq = 20497 count = 82 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.896912 last_received_ts = 553.896667 last_seq = 20497 current_ts = 553.913574 current_received_ts = 553.913330 current_seq = 20498 count = 83 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 553.913574 last_received_ts = 553.913330 last_seq = 20498 current_ts = 553.930298 current_received_ts = 553.930054 current_seq = 20499 count = 84 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 553.930298 last_received_ts = 553.930054 last_seq = 20499 current_ts = 553.946960 current_received_ts = 553.946655 current_seq = 20500 count = 85 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 553.946960 last_received_ts = 553.946655 last_seq = 20500 current_ts = 553.963623 current_received_ts = 553.963318 current_seq = 20501 count = 86 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 553.963623 last_received_ts = 553.963318 last_seq = 20501 current_ts = 553.980286 current_received_ts = 553.980042 current_seq = 20502 count = 87 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 553.980286 last_received_ts = 553.980042 last_seq = 20502 current_ts = 553.996948 current_received_ts = 553.996704 current_seq = 20503 count = 88 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 16us (kms_flip:2807) DEBUG: name = flip last_ts = 553.996948 last_received_ts = 553.996704 last_seq = 20503 current_ts = 554.013611 current_received_ts = 554.013367 current_seq = 20504 count = 89 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.013611 last_received_ts = 554.013367 last_seq = 20504 current_ts = 554.030334 current_received_ts = 554.030090 current_seq = 20505 count = 90 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.030334 last_received_ts = 554.030090 last_seq = 20505 current_ts = 554.046997 current_received_ts = 554.046692 current_seq = 20506 count = 91 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.046997 last_received_ts = 554.046692 last_seq = 20506 current_ts = 554.063660 current_received_ts = 554.063354 current_seq = 20507 count = 92 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.063660 last_received_ts = 554.063354 last_seq = 20507 current_ts = 554.080322 current_received_ts = 554.080078 current_seq = 20508 count = 93 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.080322 last_received_ts = 554.080078 last_seq = 20508 current_ts = 554.096985 current_received_ts = 554.096741 current_seq = 20509 count = 94 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.096985 last_received_ts = 554.096741 last_seq = 20509 current_ts = 554.113647 current_received_ts = 554.113403 current_seq = 20510 count = 95 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.113647 last_received_ts = 554.113403 last_seq = 20510 current_ts = 554.130371 current_received_ts = 554.130066 current_seq = 20511 count = 96 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.130371 last_received_ts = 554.130066 last_seq = 20511 current_ts = 554.147034 current_received_ts = 554.146545 current_seq = 20512 count = 97 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.147034 last_received_ts = 554.146545 last_seq = 20512 current_ts = 554.163696 current_received_ts = 554.163208 current_seq = 20513 count = 98 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.163696 last_received_ts = 554.163208 last_seq = 20513 current_ts = 554.180359 current_received_ts = 554.180054 current_seq = 20514 count = 99 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 554.180359 last_received_ts = 554.180054 last_seq = 20514 current_ts = 554.197021 current_received_ts = 554.196533 current_seq = 20515 count = 100 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 16us (kms_flip:2807) DEBUG: name = flip last_ts = 554.197021 last_received_ts = 554.196533 last_seq = 20515 current_ts = 554.213684 current_received_ts = 554.213196 current_seq = 20516 count = 101 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.213684 last_received_ts = 554.213196 last_seq = 20516 current_ts = 554.230347 current_received_ts = 554.231140 current_seq = 20517 count = 102 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 554.230347 last_received_ts = 554.231140 last_seq = 20517 current_ts = 554.247009 current_received_ts = 554.246704 current_seq = 20518 count = 103 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.247009 last_received_ts = 554.246704 last_seq = 20518 current_ts = 554.263733 current_received_ts = 554.263428 current_seq = 20519 count = 104 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.263733 last_received_ts = 554.263428 last_seq = 20519 current_ts = 554.280396 current_received_ts = 554.280090 current_seq = 20520 count = 105 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.280396 last_received_ts = 554.280090 last_seq = 20520 current_ts = 554.297058 current_received_ts = 554.296753 current_seq = 20521 count = 106 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.297058 last_received_ts = 554.296753 last_seq = 20521 current_ts = 554.313721 current_received_ts = 554.313416 current_seq = 20522 count = 107 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.313721 last_received_ts = 554.313416 last_seq = 20522 current_ts = 554.330383 current_received_ts = 554.330200 current_seq = 20523 count = 108 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.330383 last_received_ts = 554.330200 last_seq = 20523 current_ts = 554.347107 current_received_ts = 554.346741 current_seq = 20524 count = 109 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.347107 last_received_ts = 554.346741 last_seq = 20524 current_ts = 554.363770 current_received_ts = 554.363464 current_seq = 20525 count = 110 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.363770 last_received_ts = 554.363464 last_seq = 20525 current_ts = 554.380432 current_received_ts = 554.380188 current_seq = 20526 count = 111 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.380432 last_received_ts = 554.380188 last_seq = 20526 current_ts = 554.397095 current_received_ts = 554.396790 current_seq = 20527 count = 112 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.397095 last_received_ts = 554.396790 last_seq = 20527 current_ts = 554.413757 current_received_ts = 554.413513 current_seq = 20528 count = 113 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.413757 last_received_ts = 554.413513 last_seq = 20528 current_ts = 554.430420 current_received_ts = 554.430176 current_seq = 20529 count = 114 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.430420 last_received_ts = 554.430176 last_seq = 20529 current_ts = 554.447083 current_received_ts = 554.446838 current_seq = 20530 count = 115 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.447083 last_received_ts = 554.446838 last_seq = 20530 current_ts = 554.463806 current_received_ts = 554.463501 current_seq = 20531 count = 116 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.463806 last_received_ts = 554.463501 last_seq = 20531 current_ts = 554.480469 current_received_ts = 554.480164 current_seq = 20532 count = 117 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.480469 last_received_ts = 554.480164 last_seq = 20532 current_ts = 554.497131 current_received_ts = 554.496826 current_seq = 20533 count = 118 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.497131 last_received_ts = 554.496826 last_seq = 20533 current_ts = 554.513794 current_received_ts = 554.513489 current_seq = 20534 count = 119 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.513794 last_received_ts = 554.513489 last_seq = 20534 current_ts = 554.530457 current_received_ts = 554.530212 current_seq = 20535 count = 120 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.530457 last_received_ts = 554.530212 last_seq = 20535 current_ts = 554.547119 current_received_ts = 554.546875 current_seq = 20536 count = 121 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.547119 last_received_ts = 554.546875 last_seq = 20536 current_ts = 554.563843 current_received_ts = 554.563538 current_seq = 20537 count = 122 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.563843 last_received_ts = 554.563538 last_seq = 20537 current_ts = 554.580505 current_received_ts = 554.580261 current_seq = 20538 count = 123 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.580505 last_received_ts = 554.580261 last_seq = 20538 current_ts = 554.597168 current_received_ts = 554.596863 current_seq = 20539 count = 124 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.597168 last_received_ts = 554.596863 last_seq = 20539 current_ts = 554.613831 current_received_ts = 554.613525 current_seq = 20540 count = 125 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.613831 last_received_ts = 554.613525 last_seq = 20540 current_ts = 554.630493 current_received_ts = 554.630249 current_seq = 20541 count = 126 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 16us (kms_flip:2807) DEBUG: name = flip last_ts = 554.630493 last_received_ts = 554.630249 last_seq = 20541 current_ts = 554.647156 current_received_ts = 554.646851 current_seq = 20542 count = 127 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.647156 last_received_ts = 554.646851 last_seq = 20542 current_ts = 554.663818 current_received_ts = 554.663513 current_seq = 20543 count = 128 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.663818 last_received_ts = 554.663513 last_seq = 20543 current_ts = 554.680542 current_received_ts = 554.680237 current_seq = 20544 count = 129 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.680542 last_received_ts = 554.680237 last_seq = 20544 current_ts = 554.697205 current_received_ts = 554.696899 current_seq = 20545 count = 130 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.697205 last_received_ts = 554.696899 last_seq = 20545 current_ts = 554.713867 current_received_ts = 554.713562 current_seq = 20546 count = 131 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.713867 last_received_ts = 554.713562 last_seq = 20546 current_ts = 554.730530 current_received_ts = 554.730286 current_seq = 20547 count = 132 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.730530 last_received_ts = 554.730286 last_seq = 20547 current_ts = 554.747192 current_received_ts = 554.746948 current_seq = 20548 count = 133 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 48us (kms_flip:2807) DEBUG: name = flip last_ts = 554.747192 last_received_ts = 554.746948 last_seq = 20548 current_ts = 554.763855 current_received_ts = 554.763611 current_seq = 20549 count = 134 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.763855 last_received_ts = 554.763611 last_seq = 20549 current_ts = 554.780518 current_received_ts = 554.780273 current_seq = 20550 count = 135 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 554.780518 last_received_ts = 554.780273 last_seq = 20550 current_ts = 554.797241 current_received_ts = 554.796936 current_seq = 20551 count = 136 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 46us (kms_flip:2807) DEBUG: name = flip last_ts = 554.797241 last_received_ts = 554.796936 last_seq = 20551 current_ts = 554.813904 current_received_ts = 554.813599 current_seq = 20552 count = 137 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.813904 last_received_ts = 554.813599 last_seq = 20552 current_ts = 554.830566 current_received_ts = 554.830322 current_seq = 20553 count = 138 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.830566 last_received_ts = 554.830322 last_seq = 20553 current_ts = 554.847229 current_received_ts = 554.846985 current_seq = 20554 count = 139 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 46us (kms_flip:2807) DEBUG: name = flip last_ts = 554.847229 last_received_ts = 554.846985 last_seq = 20554 current_ts = 554.863892 current_received_ts = 554.863586 current_seq = 20555 count = 140 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 554.863892 last_received_ts = 554.863586 last_seq = 20555 current_ts = 554.880554 current_received_ts = 554.880249 current_seq = 20556 count = 141 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.880554 last_received_ts = 554.880249 last_seq = 20556 current_ts = 554.897278 current_received_ts = 554.896973 current_seq = 20557 count = 142 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.897278 last_received_ts = 554.896973 last_seq = 20557 current_ts = 554.913940 current_received_ts = 554.913635 current_seq = 20558 count = 143 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 554.913940 last_received_ts = 554.913635 last_seq = 20558 current_ts = 554.930603 current_received_ts = 554.930298 current_seq = 20559 count = 144 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.930603 last_received_ts = 554.930298 last_seq = 20559 current_ts = 554.947266 current_received_ts = 554.946960 current_seq = 20560 count = 145 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 34us (kms_flip:2807) DEBUG: name = flip last_ts = 554.947266 last_received_ts = 554.946960 last_seq = 20560 current_ts = 554.963928 current_received_ts = 554.963684 current_seq = 20561 count = 146 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 554.963928 last_received_ts = 554.963684 last_seq = 20561 current_ts = 554.980591 current_received_ts = 554.980347 current_seq = 20562 count = 147 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 16us (kms_flip:2807) DEBUG: name = flip last_ts = 554.980591 last_received_ts = 554.980347 last_seq = 20562 current_ts = 554.997253 current_received_ts = 554.997009 current_seq = 20563 count = 148 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 554.997253 last_received_ts = 554.997009 last_seq = 20563 current_ts = 555.013977 current_received_ts = 555.013672 current_seq = 20564 count = 149 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 555.013977 last_received_ts = 555.013672 last_seq = 20564 current_ts = 555.030640 current_received_ts = 555.030334 current_seq = 20565 count = 150 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 16us (kms_flip:2807) DEBUG: name = flip last_ts = 555.030640 last_received_ts = 555.030334 last_seq = 20565 current_ts = 555.047302 current_received_ts = 555.047058 current_seq = 20566 count = 151 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.047302 last_received_ts = 555.047058 last_seq = 20566 current_ts = 555.063965 current_received_ts = 555.063660 current_seq = 20567 count = 152 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.063965 last_received_ts = 555.063660 last_seq = 20567 current_ts = 555.080627 current_received_ts = 555.080383 current_seq = 20568 count = 153 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 17us (kms_flip:2807) DEBUG: name = flip last_ts = 555.080627 last_received_ts = 555.080383 last_seq = 20568 current_ts = 555.097290 current_received_ts = 555.097107 current_seq = 20569 count = 154 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.097290 last_received_ts = 555.097107 last_seq = 20569 current_ts = 555.114014 current_received_ts = 555.113647 current_seq = 20570 count = 155 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 555.114014 last_received_ts = 555.113647 last_seq = 20570 current_ts = 555.130676 current_received_ts = 555.130432 current_seq = 20571 count = 156 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 555.130676 last_received_ts = 555.130432 last_seq = 20571 current_ts = 555.147339 current_received_ts = 555.146973 current_seq = 20572 count = 157 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.147339 last_received_ts = 555.146973 last_seq = 20572 current_ts = 555.164001 current_received_ts = 555.163452 current_seq = 20573 count = 158 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 555.164001 last_received_ts = 555.163452 last_seq = 20573 current_ts = 555.180664 current_received_ts = 555.180176 current_seq = 20574 count = 159 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.180664 last_received_ts = 555.180176 last_seq = 20574 current_ts = 555.197327 current_received_ts = 555.196899 current_seq = 20575 count = 160 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 18us (kms_flip:2807) DEBUG: name = flip last_ts = 555.197327 last_received_ts = 555.196899 last_seq = 20575 current_ts = 555.214050 current_received_ts = 555.213745 current_seq = 20576 count = 161 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 17us (kms_flip:2807) DEBUG: name = flip last_ts = 555.214050 last_received_ts = 555.213745 last_seq = 20576 current_ts = 555.230713 current_received_ts = 555.230774 current_seq = 20577 count = 162 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.230713 last_received_ts = 555.230774 last_seq = 20577 current_ts = 555.247375 current_received_ts = 555.249084 current_seq = 20578 count = 163 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 19us (kms_flip:2807) DEBUG: name = flip last_ts = 555.247375 last_received_ts = 555.249084 last_seq = 20578 current_ts = 555.264038 current_received_ts = 555.263489 current_seq = 20579 count = 164 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.264038 last_received_ts = 555.263489 last_seq = 20579 current_ts = 555.280701 current_received_ts = 555.281067 current_seq = 20580 count = 165 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 31us (kms_flip:2807) DEBUG: name = flip last_ts = 555.280701 last_received_ts = 555.281067 last_seq = 20580 current_ts = 555.297363 current_received_ts = 555.296814 current_seq = 20581 count = 166 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 555.297363 last_received_ts = 555.296814 last_seq = 20581 current_ts = 555.314026 current_received_ts = 555.313721 current_seq = 20582 count = 167 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.314026 last_received_ts = 555.313721 last_seq = 20582 current_ts = 555.330750 current_received_ts = 555.332092 current_seq = 20583 count = 168 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 555.330750 last_received_ts = 555.332092 last_seq = 20583 current_ts = 555.347412 current_received_ts = 555.346924 current_seq = 20584 count = 169 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 555.347412 last_received_ts = 555.346924 last_seq = 20584 current_ts = 555.364075 current_received_ts = 555.363525 current_seq = 20585 count = 170 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 19us (kms_flip:2807) DEBUG: name = flip last_ts = 555.364075 last_received_ts = 555.363525 last_seq = 20585 current_ts = 555.380737 current_received_ts = 555.380981 current_seq = 20586 count = 171 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 555.380737 last_received_ts = 555.380981 last_seq = 20586 current_ts = 555.397400 current_received_ts = 555.396851 current_seq = 20587 count = 172 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.397400 last_received_ts = 555.396851 last_seq = 20587 current_ts = 555.414062 current_received_ts = 555.413757 current_seq = 20588 count = 173 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 555.414062 last_received_ts = 555.413757 last_seq = 20588 current_ts = 555.430786 current_received_ts = 555.431152 current_seq = 20589 count = 174 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 13us (kms_flip:2807) DEBUG: name = flip last_ts = 555.430786 last_received_ts = 555.431152 last_seq = 20589 current_ts = 555.447449 current_received_ts = 555.447083 current_seq = 20590 count = 175 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 16us (kms_flip:2807) DEBUG: name = flip last_ts = 555.447449 last_received_ts = 555.447083 last_seq = 20590 current_ts = 555.464111 current_received_ts = 555.465454 current_seq = 20591 count = 176 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 20us (kms_flip:2807) DEBUG: name = flip last_ts = 555.464111 last_received_ts = 555.465454 last_seq = 20591 current_ts = 555.480774 current_received_ts = 555.480225 current_seq = 20592 count = 177 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.480774 last_received_ts = 555.480225 last_seq = 20592 current_ts = 555.497437 current_received_ts = 555.497192 current_seq = 20593 count = 178 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 18us (kms_flip:2807) DEBUG: name = flip last_ts = 555.497437 last_received_ts = 555.497192 last_seq = 20593 current_ts = 555.514099 current_received_ts = 555.513977 current_seq = 20594 count = 179 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 25us (kms_flip:2807) DEBUG: name = flip last_ts = 555.514099 last_received_ts = 555.513977 last_seq = 20594 current_ts = 555.530762 current_received_ts = 555.530640 current_seq = 20595 count = 180 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 27us (kms_flip:2807) DEBUG: name = flip last_ts = 555.530762 last_received_ts = 555.530640 last_seq = 20595 current_ts = 555.547485 current_received_ts = 555.547302 current_seq = 20596 count = 181 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 25us (kms_flip:2807) DEBUG: name = flip last_ts = 555.547485 last_received_ts = 555.547302 last_seq = 20596 current_ts = 555.564148 current_received_ts = 555.563660 current_seq = 20597 count = 182 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 15us (kms_flip:2807) DEBUG: name = flip last_ts = 555.564148 last_received_ts = 555.563660 last_seq = 20597 current_ts = 555.580811 current_received_ts = 555.580261 current_seq = 20598 count = 183 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 14us (kms_flip:2807) DEBUG: name = flip last_ts = 555.580811 last_received_ts = 555.580261 last_seq = 20598 current_ts = 555.597473 current_received_ts = 555.596985 current_seq = 20599 count = 184 seq_step = 1 (kms_flip:2807) DEBUG: Vblank took 1068us (kms_flip:2807) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:2807) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2807) igt_core-INFO: Stack trace: (kms_flip:2807) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2807) igt_core-INFO: #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() (kms_flip:2807) igt_core-INFO: #2 ../tests/kms_flip.c:1887 run_test() (kms_flip:2807) igt_core-INFO: #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2043() (kms_flip:2807) igt_core-INFO: #4 ../tests/kms_flip.c:2043 main() (kms_flip:2807) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2807) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2807) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-HDMI-A2: FAIL (4.182s)
Dmesg	<6> [565.757778] [IGT] kms_flip: starting dynamic subtest B-HDMI-A2 <7> [565.762257] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:179] <7> [565.762605] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:182] <7> [565.847505] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:77:pipe A] <7> [565.847745] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [565.850084] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [565.850529] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [565.850908] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [565.855153] 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 0x0000000d, found 0x00000000) <7> [565.855635] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [565.856014] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [565.857079] 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 1920, found 0) <7> [565.857562] 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 2200, found 0) <7> [565.857937] 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 1920, found 0) <7> [565.862406] 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 2200, found 0) <7> [565.862883] 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 2008, found 0) <7> [565.864925] 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 2052, found 0) <7> [565.867115] 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 1080, found 0) <7> [565.867598] 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 1080, found 0) <7> [565.867975] 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 1083, found 0) <7> [565.869028] 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 1088, found 0) <7> [565.871100] 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 1125, found 0) <7> [565.871570] 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 1125, found 0) <7> [565.871947] 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 1920, found 0) <7> [565.875889] 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 2200, found 0) <7> [565.876641] 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 1920, found 0) <7> [565.877042] 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 2200, found 0) <7> [565.879235] 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 2008, found 0) <7> [565.879715] 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 2052, found 0) <7> [565.882113] 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 1080, found 0) <7> [565.882581] 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 1080, found 0) <7> [565.882958] 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 1083, found 0) <7> [565.884949] 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 1088, found 0) <7> [565.888683] 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 1125, found 0) <7> [565.889589] 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 1125, found 0) <7> [565.890009] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [565.890908] 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 1, found 0) <7> [565.892108] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [565.892515] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in has_hdmi_sink (expected yes, found no) <7> [565.892893] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in has_infoframe (expected yes, found no) <7> [565.896997] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0) <7> [565.898112] 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 148500, found 0) <7> [565.898499] 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 148500, found 0) <7> [565.898874] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in port_clock (expected 222750, found 0) <7> [565.900324] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000) <7> [565.900738] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000) <7> [565.903087] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in avi infoframe <7> [565.903568] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [565.903943] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [565.903948] i915 0000:00:02.0: colorspace: RGB <7> [565.903952] i915 0000:00:02.0: scan mode: Underscan <7> [565.903955] i915 0000:00:02.0: colorimetry: No Data <7> [565.903959] i915 0000:00:02.0: picture aspect: No Data <7> [565.903962] i915 0000:00:02.0: active aspect: Same as Picture <7> [565.903965] i915 0000:00:02.0: itc: No Data <7> [565.903969] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [565.903972] i915 0000:00:02.0: quantization range: Full <7> [565.903975] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [565.903979] i915 0000:00:02.0: video code: 0 <7> [565.903982] i915 0000:00:02.0: ycc quantization range: Full <7> [565.903985] i915 0000:00:02.0: hdmi content type: Graphics <7> [565.903988] i915 0000:00:02.0: pixel repeat: 0 <7> [565.903991] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [565.903995] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [565.906091] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in spd infoframe <7> [565.906544] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [565.906919] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [565.906923] i915 0000:00:02.0: vendor: Intel <7> [565.906927] i915 0000:00:02.0: product: Integrated gfx <7> [565.906930] i915 0000:00:02.0: source device information: PC General (0x9) <7> [565.906934] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [565.911095] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:77:pipe A] fastset requirement not met in hdmi infoframe <7> [565.911577] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [565.911954] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [565.911959] i915 0000:00:02.0: empty frame <7> [565.911963] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [565.913834] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:77:pipe A] fastset requirement not met, forcing full modeset <7> [565.914996] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:77:pipe A] releasing PORT PLL C <7> [565.917194] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:77:pipe A] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [565.917686] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:71:cursor A] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0 <7> [565.922202] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:77:pipe A] min cdclk: 192000 kHz -> 0 kHz <7> [565.922729] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [565.923430] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz <7> [565.923817] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4 <7> [565.925140] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:77:pipe A] enable: no [modeset] <7> [565.925598] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [NOFB], visible: no <7> [565.925982] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:44:plane 2A] fb: [NOFB], visible: no <7> [565.928055] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:plane 3A] fb: [NOFB], visible: no <7> [565.928499] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:62:plane 4A] fb: [NOFB], visible: no <7> [565.928874] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:71:cursor A] fb: [NOFB], visible: no <7> [565.932590] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:175:HDMI-A-2][ENCODER:174:DDI C/PHY C] Disable audio codec on [CRTC:77:pipe A] <7> [565.966688] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port C <7> [565.967779] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A <7> [565.979586] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10 <7> [565.985066] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time <7> [566.088132] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_C <7> [566.088659] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL C (active 0x1, on? 1) for [CRTC:77:pipe A] <7> [566.091210] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL C <7> [566.091712] 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> [566.094357] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B] <7> [566.094846] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:174:DDI C/PHY C] <7> [566.097091] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:175:HDMI-A-2] <7> [566.097792] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-c <7> [566.102580] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:77:pipe A] <7> [566.104182] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [566.104664] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz <7> [566.105059] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13 <7> [566.105600] 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> [566.106635] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:120:pipe B] <7> [566.107495] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:163:pipe C] <7> [566.107928] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:120:pipe B] <7> [566.108242] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:175:HDMI-A-2] <7> [566.108434] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [566.108935] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:120:pipe B] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [566.112120] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL <7> [566.112140] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled <7> [566.112190] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:174:DDI C/PHY C] [CRTC:120:pipe B] <7> [566.112672] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.enable (expected no, found yes) <7> [566.114059] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.active (expected no, found yes) <7> [566.114550] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1) <7> [566.114927] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in lane_count (expected 0, found 4) <7> [566.119033] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d) <7> [566.119520] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [566.119909] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [566.122359] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [566.122849] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [566.127318] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [566.127790] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [566.128484] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [566.128873] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [566.130119] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [566.130584] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [566.130958] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [566.134033] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [566.134528] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [566.134902] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [566.135887] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [566.138035] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [566.138518] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [566.138892] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [566.139308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [566.139686] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [566.144185] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [566.144662] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [566.148402] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [566.148880] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [566.149595] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [566.151475] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [566.151950] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [566.154046] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [566.154528] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [566.154903] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [566.155909] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in has_infoframe (expected no, found yes) <7> [566.161146] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [566.161617] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [566.162319] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [566.162715] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in port_clock (expected 0, found 222750) <7> [566.163625] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [566.165026] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [566.165477] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in avi infoframe <7> [566.165853] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [566.169401] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [566.169881] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [566.169888] i915 0000:00:02.0: colorspace: RGB <7> [566.169892] i915 0000:00:02.0: scan mode: Underscan <7> [566.169895] i915 0000:00:02.0: colorimetry: No Data <7> [566.169899] i915 0000:00:02.0: picture aspect: No Data <7> [566.169902] i915 0000:00:02.0: active aspect: Same as Picture <7> [566.169905] i915 0000:00:02.0: itc: No Data <7> [566.169908] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [566.169912] i915 0000:00:02.0: quantization range: Full <7> [566.169915] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [566.169918] i915 0000:00:02.0: video code: 0 <7> [566.169921] i915 0000:00:02.0: ycc quantization range: Full <7> [566.169925] i915 0000:00:02.0: hdmi content type: Graphics <7> [566.169928] i915 0000:00:02.0: pixel repeat: 0 <7> [566.169931] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [566.169936] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in spd infoframe <7> [566.173173] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [566.173664] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [566.175263] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [566.175270] i915 0000:00:02.0: vendor: Intel <7> [566.175274] i915 0000:00:02.0: product: Integrated gfx <7> [566.175277] i915 0000:00:02.0: source device information: PC General (0x9) <7> [566.175283] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hdmi infoframe <7> [566.175749] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [566.178881] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [566.179639] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [566.179645] i915 0000:00:02.0: empty frame <7> [566.179651] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:120:pipe B] fastset requirement not met, forcing full modeset <7> [566.181738] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:120:pipe B] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x2 <7> [566.183087] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:78:plane 1B] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988 <7> [566.183520] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:114:cursor B] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32 <7> [566.183891] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:78:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [566.186906] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:78:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0 <7> [566.188973] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:78:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0 <7> [566.189444] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:78:plane 1B] 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> [566.189913] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:120:pipe B] min cdclk: 0 kHz -> 192000 kHz <7> [566.193437] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:120:pipe B] using pre-allocated PORT PLL C <7> [566.193914] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:120:pipe B] reserving PORT PLL C <7> [566.194990] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:120:pipe B] enable: yes [modeset] <7> [566.195404] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [566.195778] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 36, dithering: 0 <7> [566.196667] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [566.199030] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [566.199515] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [566.199888] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [566.201973] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [566.202462] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [566.202837] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [566.202842] i915 0000:00:02.0: colorspace: RGB <7> [566.202846] i915 0000:00:02.0: scan mode: Underscan <7> [566.202850] i915 0000:00:02.0: colorimetry: No Data <7> [566.202853] i915 0000:00:02.0: picture aspect: No Data <7> [566.202856] i915 0000:00:02.0: active aspect: Same as Picture <7> [566.202859] i915 0000:00:02.0: itc: No Data <7> [566.202863] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [566.202866] i915 0000:00:02.0: quantization range: Full <7> [566.202869] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [566.202872] i915 0000:00:02.0: video code: 0 <7> [566.202875] i915 0000:00:02.0: ycc quantization range: Full <7> [566.202879] i915 0000:00:02.0: hdmi content type: Graphics <7> [566.202882] i915 0000:00:02.0: pixel repeat: 0 <7> [566.202885] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [566.202889] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [566.202893] i915 0000:00:02.0: vendor: Intel <7> [566.202896] i915 0000:00:02.0: product: Integrated gfx <7> [566.202899] i915 0000:00:02.0: source device information: PC General (0x9) <7> [566.202903] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [566.202907] i915 0000:00:02.0: empty frame <7> [566.202911] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00 <7> [566.205015] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00 <7> [566.205494] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [566.205869] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [566.209150] 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> [566.209643] 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> [566.210287] 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> [566.210674] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 <7> [566.211992] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 <7> [566.212426] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [566.212803] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [566.213782] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [566.217003] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000 <7> [566.217494] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0 <7> [566.217870] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [566.219007] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [566.219451] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [566.219826] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6200, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d <7> [566.221977] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [566.222459] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [566.222834] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [566.224986] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [566.225461] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [566.225835] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [566.227432] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [566.227902] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [566.229961] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:78:plane 1B] fb: [FB:179] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [566.230472] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [566.230847] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [566.233005] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:87:plane 2B] fb: [NOFB], visible: no <7> [566.233505] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:96:plane 3B] fb: [NOFB], visible: no <7> [566.233879] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:105:plane 4B] fb: [NOFB], visible: no <7> [566.236961] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:114:cursor B] fb: [NOFB], visible: no <7> [566.238377] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c <7> [566.239344] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:164:DDI B/PHY B] <7> [566.239766] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:174:DDI C/PHY C] <7> [566.242129] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x2, on? 0) for [CRTC:120:pipe B] <7> [566.242611] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C <7> [566.245161] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C <7> [566.245753] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe B <7> [566.264161] 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:120:pipe B], 32 bytes ELD <7> [566.280807] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000) <7> [566.283012] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N <7> [566.283681] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:175:HDMI-A-2] <7> [566.284539] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:120:pipe B] <6> [569.941283] [IGT] kms_flip: finished subtest B-HDMI-A2, FAIL

Detail

Value

Duration

4.18 seconds

Hostname

shard-glk6

Igt-Version

IGT-Version: 2.3-g246d93c1d (x86_64) (Linux: 7.0.0-rc3-CI_DRM_18142-g4082c266f293+ x86_64)

Out

Starting dynamic subtest: B-HDMI-A2
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2122 __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 B-HDMI-A2: FAIL (4.182s)

Err

Starting dynamic subtest: B-HDMI-A2
(kms_flip:2807) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:2807) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest B-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.563477
last_received_ts = 553.563232
last_seq = 20477
current_ts = 553.580139
current_received_ts = 553.579895
current_seq = 20478
count = 63
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.580139
last_received_ts = 553.579895
last_seq = 20478
current_ts = 553.596863
current_received_ts = 553.596558
current_seq = 20479
count = 64
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.596863
last_received_ts = 553.596558
last_seq = 20479
current_ts = 553.613525
current_received_ts = 553.613281
current_seq = 20480
count = 65
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.613525
last_received_ts = 553.613281
last_seq = 20480
current_ts = 553.630188
current_received_ts = 553.629883
current_seq = 20481
count = 66
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.630188
last_received_ts = 553.629883
last_seq = 20481
current_ts = 553.646851
current_received_ts = 553.646545
current_seq = 20482
count = 67
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.646851
last_received_ts = 553.646545
last_seq = 20482
current_ts = 553.663513
current_received_ts = 553.663269
current_seq = 20483
count = 68
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.663513
last_received_ts = 553.663269
last_seq = 20483
current_ts = 553.680176
current_received_ts = 553.679932
current_seq = 20484
count = 69
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.680176
last_received_ts = 553.679932
last_seq = 20484
current_ts = 553.696838
current_received_ts = 553.696411
current_seq = 20485
count = 70
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.696838
last_received_ts = 553.696411
last_seq = 20485
current_ts = 553.713562
current_received_ts = 553.713257
current_seq = 20486
count = 71
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.713562
last_received_ts = 553.713257
last_seq = 20486
current_ts = 553.730225
current_received_ts = 553.729919
current_seq = 20487
count = 72
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.730225
last_received_ts = 553.729919
last_seq = 20487
current_ts = 553.746887
current_received_ts = 553.746643
current_seq = 20488
count = 73
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.746887
last_received_ts = 553.746643
last_seq = 20488
current_ts = 553.763550
current_received_ts = 553.763306
current_seq = 20489
count = 74
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.763550
last_received_ts = 553.763306
last_seq = 20489
current_ts = 553.780212
current_received_ts = 553.779907
current_seq = 20490
count = 75
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.780212
last_received_ts = 553.779907
last_seq = 20490
current_ts = 553.796875
current_received_ts = 553.796631
current_seq = 20491
count = 76
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.796875
last_received_ts = 553.796631
last_seq = 20491
current_ts = 553.813538
current_received_ts = 553.813293
current_seq = 20492
count = 77
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.813538
last_received_ts = 553.813293
last_seq = 20492
current_ts = 553.830261
current_received_ts = 553.829956
current_seq = 20493
count = 78
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.830261
last_received_ts = 553.829956
last_seq = 20493
current_ts = 553.846924
current_received_ts = 553.846619
current_seq = 20494
count = 79
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.846924
last_received_ts = 553.846619
last_seq = 20494
current_ts = 553.863586
current_received_ts = 553.863342
current_seq = 20495
count = 80
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.863586
last_received_ts = 553.863342
last_seq = 20495
current_ts = 553.880249
current_received_ts = 553.880005
current_seq = 20496
count = 81
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.880249
last_received_ts = 553.880005
last_seq = 20496
current_ts = 553.896912
current_received_ts = 553.896667
current_seq = 20497
count = 82
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.896912
last_received_ts = 553.896667
last_seq = 20497
current_ts = 553.913574
current_received_ts = 553.913330
current_seq = 20498
count = 83
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.913574
last_received_ts = 553.913330
last_seq = 20498
current_ts = 553.930298
current_received_ts = 553.930054
current_seq = 20499
count = 84
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.930298
last_received_ts = 553.930054
last_seq = 20499
current_ts = 553.946960
current_received_ts = 553.946655
current_seq = 20500
count = 85
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.946960
last_received_ts = 553.946655
last_seq = 20500
current_ts = 553.963623
current_received_ts = 553.963318
current_seq = 20501
count = 86
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.963623
last_received_ts = 553.963318
last_seq = 20501
current_ts = 553.980286
current_received_ts = 553.980042
current_seq = 20502
count = 87
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.980286
last_received_ts = 553.980042
last_seq = 20502
current_ts = 553.996948
current_received_ts = 553.996704
current_seq = 20503
count = 88
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 16us
(kms_flip:2807) DEBUG: name = flip
last_ts = 553.996948
last_received_ts = 553.996704
last_seq = 20503
current_ts = 554.013611
current_received_ts = 554.013367
current_seq = 20504
count = 89
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.013611
last_received_ts = 554.013367
last_seq = 20504
current_ts = 554.030334
current_received_ts = 554.030090
current_seq = 20505
count = 90
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.030334
last_received_ts = 554.030090
last_seq = 20505
current_ts = 554.046997
current_received_ts = 554.046692
current_seq = 20506
count = 91
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.046997
last_received_ts = 554.046692
last_seq = 20506
current_ts = 554.063660
current_received_ts = 554.063354
current_seq = 20507
count = 92
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.063660
last_received_ts = 554.063354
last_seq = 20507
current_ts = 554.080322
current_received_ts = 554.080078
current_seq = 20508
count = 93
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.080322
last_received_ts = 554.080078
last_seq = 20508
current_ts = 554.096985
current_received_ts = 554.096741
current_seq = 20509
count = 94
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.096985
last_received_ts = 554.096741
last_seq = 20509
current_ts = 554.113647
current_received_ts = 554.113403
current_seq = 20510
count = 95
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.113647
last_received_ts = 554.113403
last_seq = 20510
current_ts = 554.130371
current_received_ts = 554.130066
current_seq = 20511
count = 96
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.130371
last_received_ts = 554.130066
last_seq = 20511
current_ts = 554.147034
current_received_ts = 554.146545
current_seq = 20512
count = 97
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.147034
last_received_ts = 554.146545
last_seq = 20512
current_ts = 554.163696
current_received_ts = 554.163208
current_seq = 20513
count = 98
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.163696
last_received_ts = 554.163208
last_seq = 20513
current_ts = 554.180359
current_received_ts = 554.180054
current_seq = 20514
count = 99
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.180359
last_received_ts = 554.180054
last_seq = 20514
current_ts = 554.197021
current_received_ts = 554.196533
current_seq = 20515
count = 100
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 16us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.197021
last_received_ts = 554.196533
last_seq = 20515
current_ts = 554.213684
current_received_ts = 554.213196
current_seq = 20516
count = 101
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.213684
last_received_ts = 554.213196
last_seq = 20516
current_ts = 554.230347
current_received_ts = 554.231140
current_seq = 20517
count = 102
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.230347
last_received_ts = 554.231140
last_seq = 20517
current_ts = 554.247009
current_received_ts = 554.246704
current_seq = 20518
count = 103
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.247009
last_received_ts = 554.246704
last_seq = 20518
current_ts = 554.263733
current_received_ts = 554.263428
current_seq = 20519
count = 104
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.263733
last_received_ts = 554.263428
last_seq = 20519
current_ts = 554.280396
current_received_ts = 554.280090
current_seq = 20520
count = 105
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.280396
last_received_ts = 554.280090
last_seq = 20520
current_ts = 554.297058
current_received_ts = 554.296753
current_seq = 20521
count = 106
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.297058
last_received_ts = 554.296753
last_seq = 20521
current_ts = 554.313721
current_received_ts = 554.313416
current_seq = 20522
count = 107
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.313721
last_received_ts = 554.313416
last_seq = 20522
current_ts = 554.330383
current_received_ts = 554.330200
current_seq = 20523
count = 108
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.330383
last_received_ts = 554.330200
last_seq = 20523
current_ts = 554.347107
current_received_ts = 554.346741
current_seq = 20524
count = 109
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.347107
last_received_ts = 554.346741
last_seq = 20524
current_ts = 554.363770
current_received_ts = 554.363464
current_seq = 20525
count = 110
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.363770
last_received_ts = 554.363464
last_seq = 20525
current_ts = 554.380432
current_received_ts = 554.380188
current_seq = 20526
count = 111
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.380432
last_received_ts = 554.380188
last_seq = 20526
current_ts = 554.397095
current_received_ts = 554.396790
current_seq = 20527
count = 112
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.397095
last_received_ts = 554.396790
last_seq = 20527
current_ts = 554.413757
current_received_ts = 554.413513
current_seq = 20528
count = 113
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.413757
last_received_ts = 554.413513
last_seq = 20528
current_ts = 554.430420
current_received_ts = 554.430176
current_seq = 20529
count = 114
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.430420
last_received_ts = 554.430176
last_seq = 20529
current_ts = 554.447083
current_received_ts = 554.446838
current_seq = 20530
count = 115
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.447083
last_received_ts = 554.446838
last_seq = 20530
current_ts = 554.463806
current_received_ts = 554.463501
current_seq = 20531
count = 116
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.463806
last_received_ts = 554.463501
last_seq = 20531
current_ts = 554.480469
current_received_ts = 554.480164
current_seq = 20532
count = 117
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.480469
last_received_ts = 554.480164
last_seq = 20532
current_ts = 554.497131
current_received_ts = 554.496826
current_seq = 20533
count = 118
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.497131
last_received_ts = 554.496826
last_seq = 20533
current_ts = 554.513794
current_received_ts = 554.513489
current_seq = 20534
count = 119
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.513794
last_received_ts = 554.513489
last_seq = 20534
current_ts = 554.530457
current_received_ts = 554.530212
current_seq = 20535
count = 120
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.530457
last_received_ts = 554.530212
last_seq = 20535
current_ts = 554.547119
current_received_ts = 554.546875
current_seq = 20536
count = 121
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.547119
last_received_ts = 554.546875
last_seq = 20536
current_ts = 554.563843
current_received_ts = 554.563538
current_seq = 20537
count = 122
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.563843
last_received_ts = 554.563538
last_seq = 20537
current_ts = 554.580505
current_received_ts = 554.580261
current_seq = 20538
count = 123
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.580505
last_received_ts = 554.580261
last_seq = 20538
current_ts = 554.597168
current_received_ts = 554.596863
current_seq = 20539
count = 124
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.597168
last_received_ts = 554.596863
last_seq = 20539
current_ts = 554.613831
current_received_ts = 554.613525
current_seq = 20540
count = 125
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.613831
last_received_ts = 554.613525
last_seq = 20540
current_ts = 554.630493
current_received_ts = 554.630249
current_seq = 20541
count = 126
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 16us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.630493
last_received_ts = 554.630249
last_seq = 20541
current_ts = 554.647156
current_received_ts = 554.646851
current_seq = 20542
count = 127
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.647156
last_received_ts = 554.646851
last_seq = 20542
current_ts = 554.663818
current_received_ts = 554.663513
current_seq = 20543
count = 128
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.663818
last_received_ts = 554.663513
last_seq = 20543
current_ts = 554.680542
current_received_ts = 554.680237
current_seq = 20544
count = 129
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.680542
last_received_ts = 554.680237
last_seq = 20544
current_ts = 554.697205
current_received_ts = 554.696899
current_seq = 20545
count = 130
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.697205
last_received_ts = 554.696899
last_seq = 20545
current_ts = 554.713867
current_received_ts = 554.713562
current_seq = 20546
count = 131
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.713867
last_received_ts = 554.713562
last_seq = 20546
current_ts = 554.730530
current_received_ts = 554.730286
current_seq = 20547
count = 132
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.730530
last_received_ts = 554.730286
last_seq = 20547
current_ts = 554.747192
current_received_ts = 554.746948
current_seq = 20548
count = 133
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 48us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.747192
last_received_ts = 554.746948
last_seq = 20548
current_ts = 554.763855
current_received_ts = 554.763611
current_seq = 20549
count = 134
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.763855
last_received_ts = 554.763611
last_seq = 20549
current_ts = 554.780518
current_received_ts = 554.780273
current_seq = 20550
count = 135
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.780518
last_received_ts = 554.780273
last_seq = 20550
current_ts = 554.797241
current_received_ts = 554.796936
current_seq = 20551
count = 136
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 46us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.797241
last_received_ts = 554.796936
last_seq = 20551
current_ts = 554.813904
current_received_ts = 554.813599
current_seq = 20552
count = 137
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.813904
last_received_ts = 554.813599
last_seq = 20552
current_ts = 554.830566
current_received_ts = 554.830322
current_seq = 20553
count = 138
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.830566
last_received_ts = 554.830322
last_seq = 20553
current_ts = 554.847229
current_received_ts = 554.846985
current_seq = 20554
count = 139
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 46us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.847229
last_received_ts = 554.846985
last_seq = 20554
current_ts = 554.863892
current_received_ts = 554.863586
current_seq = 20555
count = 140
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.863892
last_received_ts = 554.863586
last_seq = 20555
current_ts = 554.880554
current_received_ts = 554.880249
current_seq = 20556
count = 141
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.880554
last_received_ts = 554.880249
last_seq = 20556
current_ts = 554.897278
current_received_ts = 554.896973
current_seq = 20557
count = 142
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.897278
last_received_ts = 554.896973
last_seq = 20557
current_ts = 554.913940
current_received_ts = 554.913635
current_seq = 20558
count = 143
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.913940
last_received_ts = 554.913635
last_seq = 20558
current_ts = 554.930603
current_received_ts = 554.930298
current_seq = 20559
count = 144
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.930603
last_received_ts = 554.930298
last_seq = 20559
current_ts = 554.947266
current_received_ts = 554.946960
current_seq = 20560
count = 145
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 34us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.947266
last_received_ts = 554.946960
last_seq = 20560
current_ts = 554.963928
current_received_ts = 554.963684
current_seq = 20561
count = 146
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.963928
last_received_ts = 554.963684
last_seq = 20561
current_ts = 554.980591
current_received_ts = 554.980347
current_seq = 20562
count = 147
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 16us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.980591
last_received_ts = 554.980347
last_seq = 20562
current_ts = 554.997253
current_received_ts = 554.997009
current_seq = 20563
count = 148
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 554.997253
last_received_ts = 554.997009
last_seq = 20563
current_ts = 555.013977
current_received_ts = 555.013672
current_seq = 20564
count = 149
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.013977
last_received_ts = 555.013672
last_seq = 20564
current_ts = 555.030640
current_received_ts = 555.030334
current_seq = 20565
count = 150
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 16us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.030640
last_received_ts = 555.030334
last_seq = 20565
current_ts = 555.047302
current_received_ts = 555.047058
current_seq = 20566
count = 151
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.047302
last_received_ts = 555.047058
last_seq = 20566
current_ts = 555.063965
current_received_ts = 555.063660
current_seq = 20567
count = 152
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.063965
last_received_ts = 555.063660
last_seq = 20567
current_ts = 555.080627
current_received_ts = 555.080383
current_seq = 20568
count = 153
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 17us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.080627
last_received_ts = 555.080383
last_seq = 20568
current_ts = 555.097290
current_received_ts = 555.097107
current_seq = 20569
count = 154
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.097290
last_received_ts = 555.097107
last_seq = 20569
current_ts = 555.114014
current_received_ts = 555.113647
current_seq = 20570
count = 155
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.114014
last_received_ts = 555.113647
last_seq = 20570
current_ts = 555.130676
current_received_ts = 555.130432
current_seq = 20571
count = 156
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.130676
last_received_ts = 555.130432
last_seq = 20571
current_ts = 555.147339
current_received_ts = 555.146973
current_seq = 20572
count = 157
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.147339
last_received_ts = 555.146973
last_seq = 20572
current_ts = 555.164001
current_received_ts = 555.163452
current_seq = 20573
count = 158
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.164001
last_received_ts = 555.163452
last_seq = 20573
current_ts = 555.180664
current_received_ts = 555.180176
current_seq = 20574
count = 159
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.180664
last_received_ts = 555.180176
last_seq = 20574
current_ts = 555.197327
current_received_ts = 555.196899
current_seq = 20575
count = 160
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 18us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.197327
last_received_ts = 555.196899
last_seq = 20575
current_ts = 555.214050
current_received_ts = 555.213745
current_seq = 20576
count = 161
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 17us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.214050
last_received_ts = 555.213745
last_seq = 20576
current_ts = 555.230713
current_received_ts = 555.230774
current_seq = 20577
count = 162
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.230713
last_received_ts = 555.230774
last_seq = 20577
current_ts = 555.247375
current_received_ts = 555.249084
current_seq = 20578
count = 163
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 19us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.247375
last_received_ts = 555.249084
last_seq = 20578
current_ts = 555.264038
current_received_ts = 555.263489
current_seq = 20579
count = 164
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.264038
last_received_ts = 555.263489
last_seq = 20579
current_ts = 555.280701
current_received_ts = 555.281067
current_seq = 20580
count = 165
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 31us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.280701
last_received_ts = 555.281067
last_seq = 20580
current_ts = 555.297363
current_received_ts = 555.296814
current_seq = 20581
count = 166
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.297363
last_received_ts = 555.296814
last_seq = 20581
current_ts = 555.314026
current_received_ts = 555.313721
current_seq = 20582
count = 167
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.314026
last_received_ts = 555.313721
last_seq = 20582
current_ts = 555.330750
current_received_ts = 555.332092
current_seq = 20583
count = 168
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.330750
last_received_ts = 555.332092
last_seq = 20583
current_ts = 555.347412
current_received_ts = 555.346924
current_seq = 20584
count = 169
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.347412
last_received_ts = 555.346924
last_seq = 20584
current_ts = 555.364075
current_received_ts = 555.363525
current_seq = 20585
count = 170
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 19us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.364075
last_received_ts = 555.363525
last_seq = 20585
current_ts = 555.380737
current_received_ts = 555.380981
current_seq = 20586
count = 171
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.380737
last_received_ts = 555.380981
last_seq = 20586
current_ts = 555.397400
current_received_ts = 555.396851
current_seq = 20587
count = 172
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.397400
last_received_ts = 555.396851
last_seq = 20587
current_ts = 555.414062
current_received_ts = 555.413757
current_seq = 20588
count = 173
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.414062
last_received_ts = 555.413757
last_seq = 20588
current_ts = 555.430786
current_received_ts = 555.431152
current_seq = 20589
count = 174
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 13us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.430786
last_received_ts = 555.431152
last_seq = 20589
current_ts = 555.447449
current_received_ts = 555.447083
current_seq = 20590
count = 175
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 16us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.447449
last_received_ts = 555.447083
last_seq = 20590
current_ts = 555.464111
current_received_ts = 555.465454
current_seq = 20591
count = 176
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 20us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.464111
last_received_ts = 555.465454
last_seq = 20591
current_ts = 555.480774
current_received_ts = 555.480225
current_seq = 20592
count = 177
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.480774
last_received_ts = 555.480225
last_seq = 20592
current_ts = 555.497437
current_received_ts = 555.497192
current_seq = 20593
count = 178
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 18us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.497437
last_received_ts = 555.497192
last_seq = 20593
current_ts = 555.514099
current_received_ts = 555.513977
current_seq = 20594
count = 179
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 25us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.514099
last_received_ts = 555.513977
last_seq = 20594
current_ts = 555.530762
current_received_ts = 555.530640
current_seq = 20595
count = 180
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 27us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.530762
last_received_ts = 555.530640
last_seq = 20595
current_ts = 555.547485
current_received_ts = 555.547302
current_seq = 20596
count = 181
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 25us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.547485
last_received_ts = 555.547302
last_seq = 20596
current_ts = 555.564148
current_received_ts = 555.563660
current_seq = 20597
count = 182
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 15us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.564148
last_received_ts = 555.563660
last_seq = 20597
current_ts = 555.580811
current_received_ts = 555.580261
current_seq = 20598
count = 183
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 14us
(kms_flip:2807) DEBUG: name = flip
last_ts = 555.580811
last_received_ts = 555.580261
last_seq = 20598
current_ts = 555.597473
current_received_ts = 555.596985
current_seq = 20599
count = 184
seq_step = 1
(kms_flip:2807) DEBUG: Vblank took 1068us
(kms_flip:2807) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:2807) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2807) igt_core-INFO: Stack trace:
(kms_flip:2807) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2807) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:2807) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:2807) igt_core-INFO:   #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2043()
(kms_flip:2807) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:2807) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2807) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2807) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-HDMI-A2: FAIL (4.182s)

Dmesg

<6> [565.757778] [IGT] kms_flip: starting dynamic subtest B-HDMI-A2

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

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

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

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

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

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

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

<7> [565.855153] 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 0x0000000d, found 0x00000000)

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

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

<7> [565.857079] 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 1920, found 0)

<7> [565.857562] 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 2200, found 0)

<7> [565.857937] 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 1920, found 0)

<7> [565.862406] 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 2200, found 0)

<7> [565.862883] 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 2008, found 0)

<7> [565.864925] 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 2052, found 0)

<7> [565.867115] 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 1080, found 0)

<7> [565.867598] 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 1080, found 0)

<7> [565.867975] 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 1083, found 0)

<7> [565.869028] 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 1088, found 0)

<7> [565.871100] 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 1125, found 0)

<7> [565.871570] 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 1125, found 0)

<7> [565.871947] 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 1920, found 0)

<7> [565.875889] 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 2200, found 0)

<7> [565.876641] 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 1920, found 0)

<7> [565.877042] 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 2200, found 0)

<7> [565.879235] 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 2008, found 0)

<7> [565.879715] 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 2052, found 0)

<7> [565.882113] 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 1080, found 0)

<7> [565.882581] 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 1080, found 0)

<7> [565.882958] 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 1083, found 0)

<7> [565.884949] 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 1088, found 0)

<7> [565.888683] 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 1125, found 0)

<7> [565.889589] 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 1125, found 0)

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

<7> [565.890908] 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 1, found 0)

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

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

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

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

<7> [565.898112] 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 148500, found 0)

<7> [565.898499] 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 148500, found 0)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [565.914996] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:77:pipe A] releasing PORT PLL C

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

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

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

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

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

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

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

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

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

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

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

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

<7> [565.932590] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:175:HDMI-A-2][ENCODER:174:DDI C/PHY C] Disable audio codec on [CRTC:77:pipe A]

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

<7> [565.967779] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A

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

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

<7> [566.088132] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_C

<7> [566.088659] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL C (active 0x1, on? 1) for [CRTC:77:pipe A]

<7> [566.091210] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL C

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

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

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

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

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

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

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

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

<7> [566.105600] 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> [566.106635] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:120:pipe B]

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

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

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

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

<7> [566.108935] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:120:pipe B] hw max bpp: 36, pipe bpp: 36, dithering: 0

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

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

<7> [566.112190] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:174:DDI C/PHY C] [CRTC:120:pipe B]

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

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

<7> [566.114550] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [566.165477] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in avi infoframe

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [566.169936] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in spd infoframe

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

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

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

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

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

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

<7> [566.175283] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:120:pipe B] fastset requirement not met in hdmi infoframe

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

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

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

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

<7> [566.179651] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:120:pipe B] fastset requirement not met, forcing full modeset

<7> [566.181738] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:120:pipe B] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x2

<7> [566.183087] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:78:plane 1B] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988

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

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

<7> [566.186906] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:78:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0

<7> [566.188973] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:78:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0

<7> [566.189444] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:78:plane 1B] 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> [566.189913] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:120:pipe B] min cdclk: 0 kHz -> 192000 kHz

<7> [566.193437] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:120:pipe B] using pre-allocated PORT PLL C

<7> [566.193914] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:120:pipe B] reserving PORT PLL C

<7> [566.194990] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:120:pipe B] enable: yes [modeset]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [566.209150] 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> [566.209643] 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> [566.210287] 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> [566.210674] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [566.233005] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:87:plane 2B] fb: [NOFB], visible: no

<7> [566.233505] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:96:plane 3B] fb: [NOFB], visible: no

<7> [566.233879] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:105:plane 4B] fb: [NOFB], visible: no

<7> [566.236961] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:114:cursor B] fb: [NOFB], visible: no

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

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

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

<7> [566.242129] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x2, on? 0) for [CRTC:120:pipe B]

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

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

<7> [566.245753] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe B

<7> [566.264161] 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:120:pipe B], 32 bytes ELD

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

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

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

<7> [566.284539] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:120:pipe B]

<6> [569.941283] [IGT] kms_flip: finished subtest B-HDMI-A2, FAIL

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