igt@kms_flip@flip-vs-expired-vblank@a-hdmi-a1 on shard-snb@CI_DRM

Detail	Value
Duration	7.85 seconds
Hostname	shard-snb6
Igt-Version	IGT-Version: 2.4-g1aba4b364 (x86_64) (Linux: 7.0.0-CI_DRM_18357-g95fbbe4877e1+ x86_64)
Out	Starting dynamic subtest: A-HDMI-A1 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A1: FAIL (7.846s)
Err	Starting dynamic subtest: A-HDMI-A1 (kms_flip:2748) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2748) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-HDMI-A1 failed. ** DEBUG (kms_flip:2748) DEBUG: name = flip last_ts = 327.431702 last_received_ts = 327.431305 last_seq = 12758 current_ts = 327.448334 current_received_ts = 327.447937 current_seq = 12759 count = 316 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.448334 last_received_ts = 327.447937 last_seq = 12759 current_ts = 327.464966 current_received_ts = 327.464508 current_seq = 12760 count = 317 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.464966 last_received_ts = 327.464508 last_seq = 12760 current_ts = 327.481567 current_received_ts = 327.481140 current_seq = 12761 count = 318 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.481567 last_received_ts = 327.481140 last_seq = 12761 current_ts = 327.498199 current_received_ts = 327.497742 current_seq = 12762 count = 319 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.498199 last_received_ts = 327.497742 last_seq = 12762 current_ts = 327.514832 current_received_ts = 327.514374 current_seq = 12763 count = 320 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.514832 last_received_ts = 327.514374 last_seq = 12763 current_ts = 327.531464 current_received_ts = 327.531036 current_seq = 12764 count = 321 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.531464 last_received_ts = 327.531036 last_seq = 12764 current_ts = 327.548096 current_received_ts = 327.547668 current_seq = 12765 count = 322 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.548096 last_received_ts = 327.547668 last_seq = 12765 current_ts = 327.564728 current_received_ts = 327.564270 current_seq = 12766 count = 323 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 5us (kms_flip:2748) DEBUG: name = flip last_ts = 327.564728 last_received_ts = 327.564270 last_seq = 12766 current_ts = 327.581360 current_received_ts = 327.580933 current_seq = 12767 count = 324 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.581360 last_received_ts = 327.580933 last_seq = 12767 current_ts = 327.597992 current_received_ts = 327.597565 current_seq = 12768 count = 325 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.597992 last_received_ts = 327.597565 last_seq = 12768 current_ts = 327.614624 current_received_ts = 327.614166 current_seq = 12769 count = 326 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.614624 last_received_ts = 327.614166 last_seq = 12769 current_ts = 327.631256 current_received_ts = 327.630829 current_seq = 12770 count = 327 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.631256 last_received_ts = 327.630829 last_seq = 12770 current_ts = 327.647888 current_received_ts = 327.647461 current_seq = 12771 count = 328 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.647888 last_received_ts = 327.647461 last_seq = 12771 current_ts = 327.664520 current_received_ts = 327.664093 current_seq = 12772 count = 329 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.664520 last_received_ts = 327.664093 last_seq = 12772 current_ts = 327.681122 current_received_ts = 327.680664 current_seq = 12773 count = 330 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.681122 last_received_ts = 327.680664 last_seq = 12773 current_ts = 327.697754 current_received_ts = 327.697296 current_seq = 12774 count = 331 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.697754 last_received_ts = 327.697296 last_seq = 12774 current_ts = 327.714386 current_received_ts = 327.713928 current_seq = 12775 count = 332 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.714386 last_received_ts = 327.713928 last_seq = 12775 current_ts = 327.731018 current_received_ts = 327.730560 current_seq = 12776 count = 333 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.731018 last_received_ts = 327.730560 last_seq = 12776 current_ts = 327.747650 current_received_ts = 327.747192 current_seq = 12777 count = 334 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.747650 last_received_ts = 327.747192 last_seq = 12777 current_ts = 327.764282 current_received_ts = 327.763824 current_seq = 12778 count = 335 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 6us (kms_flip:2748) DEBUG: name = flip last_ts = 327.764282 last_received_ts = 327.763824 last_seq = 12778 current_ts = 327.780914 current_received_ts = 327.780457 current_seq = 12779 count = 336 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.780914 last_received_ts = 327.780457 last_seq = 12779 current_ts = 327.797546 current_received_ts = 327.797089 current_seq = 12780 count = 337 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.797546 last_received_ts = 327.797089 last_seq = 12780 current_ts = 327.814178 current_received_ts = 327.813721 current_seq = 12781 count = 338 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.814178 last_received_ts = 327.813721 last_seq = 12781 current_ts = 327.830811 current_received_ts = 327.830353 current_seq = 12782 count = 339 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.830811 last_received_ts = 327.830353 last_seq = 12782 current_ts = 327.847412 current_received_ts = 327.846954 current_seq = 12783 count = 340 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.847412 last_received_ts = 327.846954 last_seq = 12783 current_ts = 327.864044 current_received_ts = 327.863617 current_seq = 12784 count = 341 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.864044 last_received_ts = 327.863617 last_seq = 12784 current_ts = 327.880676 current_received_ts = 327.880249 current_seq = 12785 count = 342 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.880676 last_received_ts = 327.880249 last_seq = 12785 current_ts = 327.897308 current_received_ts = 327.896881 current_seq = 12786 count = 343 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.897308 last_received_ts = 327.896881 last_seq = 12786 current_ts = 327.913940 current_received_ts = 327.913513 current_seq = 12787 count = 344 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.913940 last_received_ts = 327.913513 last_seq = 12787 current_ts = 327.930573 current_received_ts = 327.930145 current_seq = 12788 count = 345 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.930573 last_received_ts = 327.930145 last_seq = 12788 current_ts = 327.947205 current_received_ts = 327.946747 current_seq = 12789 count = 346 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.947205 last_received_ts = 327.946747 last_seq = 12789 current_ts = 327.963837 current_received_ts = 327.963409 current_seq = 12790 count = 347 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.963837 last_received_ts = 327.963409 last_seq = 12790 current_ts = 327.980469 current_received_ts = 327.980042 current_seq = 12791 count = 348 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 327.980469 last_received_ts = 327.980042 last_seq = 12791 current_ts = 327.997101 current_received_ts = 327.996643 current_seq = 12792 count = 349 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 327.997101 last_received_ts = 327.996643 last_seq = 12792 current_ts = 328.013733 current_received_ts = 328.013275 current_seq = 12793 count = 350 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.013733 last_received_ts = 328.013275 last_seq = 12793 current_ts = 328.030334 current_received_ts = 328.029907 current_seq = 12794 count = 351 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.030334 last_received_ts = 328.029907 last_seq = 12794 current_ts = 328.046967 current_received_ts = 328.046539 current_seq = 12795 count = 352 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.046967 last_received_ts = 328.046539 last_seq = 12795 current_ts = 328.063599 current_received_ts = 328.063171 current_seq = 12796 count = 353 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.063599 last_received_ts = 328.063171 last_seq = 12796 current_ts = 328.080231 current_received_ts = 328.079803 current_seq = 12797 count = 354 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.080231 last_received_ts = 328.079803 last_seq = 12797 current_ts = 328.096863 current_received_ts = 328.096405 current_seq = 12798 count = 355 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.096863 last_received_ts = 328.096405 last_seq = 12798 current_ts = 328.113495 current_received_ts = 328.113068 current_seq = 12799 count = 356 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.113495 last_received_ts = 328.113068 last_seq = 12799 current_ts = 328.130127 current_received_ts = 328.129669 current_seq = 12800 count = 357 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.130127 last_received_ts = 328.129669 last_seq = 12800 current_ts = 328.146759 current_received_ts = 328.146301 current_seq = 12801 count = 358 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.146759 last_received_ts = 328.146301 last_seq = 12801 current_ts = 328.163391 current_received_ts = 328.162964 current_seq = 12802 count = 359 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.163391 last_received_ts = 328.162964 last_seq = 12802 current_ts = 328.180023 current_received_ts = 328.179565 current_seq = 12803 count = 360 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.180023 last_received_ts = 328.179565 last_seq = 12803 current_ts = 328.196655 current_received_ts = 328.196198 current_seq = 12804 count = 361 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.196655 last_received_ts = 328.196198 last_seq = 12804 current_ts = 328.213257 current_received_ts = 328.212830 current_seq = 12805 count = 362 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.213257 last_received_ts = 328.212830 last_seq = 12805 current_ts = 328.229889 current_received_ts = 328.229462 current_seq = 12806 count = 363 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.229889 last_received_ts = 328.229462 last_seq = 12806 current_ts = 328.246521 current_received_ts = 328.246124 current_seq = 12807 count = 364 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.246521 last_received_ts = 328.246124 last_seq = 12807 current_ts = 328.263153 current_received_ts = 328.262726 current_seq = 12808 count = 365 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.263153 last_received_ts = 328.262726 last_seq = 12808 current_ts = 328.279785 current_received_ts = 328.279266 current_seq = 12809 count = 366 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.279785 last_received_ts = 328.279266 last_seq = 12809 current_ts = 328.296417 current_received_ts = 328.295990 current_seq = 12810 count = 367 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.296417 last_received_ts = 328.295990 last_seq = 12810 current_ts = 328.313049 current_received_ts = 328.312622 current_seq = 12811 count = 368 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.313049 last_received_ts = 328.312622 last_seq = 12811 current_ts = 328.329681 current_received_ts = 328.329254 current_seq = 12812 count = 369 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.329681 last_received_ts = 328.329254 last_seq = 12812 current_ts = 328.346313 current_received_ts = 328.345825 current_seq = 12813 count = 370 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.346313 last_received_ts = 328.345825 last_seq = 12813 current_ts = 328.362946 current_received_ts = 328.362488 current_seq = 12814 count = 371 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.362946 last_received_ts = 328.362488 last_seq = 12814 current_ts = 328.379578 current_received_ts = 328.379120 current_seq = 12815 count = 372 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.379578 last_received_ts = 328.379120 last_seq = 12815 current_ts = 328.396210 current_received_ts = 328.395752 current_seq = 12816 count = 373 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.396210 last_received_ts = 328.395752 last_seq = 12816 current_ts = 328.412811 current_received_ts = 328.412384 current_seq = 12817 count = 374 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.412811 last_received_ts = 328.412384 last_seq = 12817 current_ts = 328.429443 current_received_ts = 328.429047 current_seq = 12818 count = 375 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 17us (kms_flip:2748) DEBUG: name = flip last_ts = 328.429443 last_received_ts = 328.429047 last_seq = 12818 current_ts = 328.446075 current_received_ts = 328.445618 current_seq = 12819 count = 376 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 9us (kms_flip:2748) DEBUG: name = flip last_ts = 328.446075 last_received_ts = 328.445618 last_seq = 12819 current_ts = 328.462708 current_received_ts = 328.462250 current_seq = 12820 count = 377 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 9us (kms_flip:2748) DEBUG: name = flip last_ts = 328.462708 last_received_ts = 328.462250 last_seq = 12820 current_ts = 328.479340 current_received_ts = 328.478912 current_seq = 12821 count = 378 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.479340 last_received_ts = 328.478912 last_seq = 12821 current_ts = 328.495972 current_received_ts = 328.495514 current_seq = 12822 count = 379 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.495972 last_received_ts = 328.495514 last_seq = 12822 current_ts = 328.512604 current_received_ts = 328.512146 current_seq = 12823 count = 380 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.512604 last_received_ts = 328.512146 last_seq = 12823 current_ts = 328.529236 current_received_ts = 328.528778 current_seq = 12824 count = 381 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 9us (kms_flip:2748) DEBUG: name = flip last_ts = 328.529236 last_received_ts = 328.528778 last_seq = 12824 current_ts = 328.545868 current_received_ts = 328.545410 current_seq = 12825 count = 382 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.545868 last_received_ts = 328.545410 last_seq = 12825 current_ts = 328.562500 current_received_ts = 328.562073 current_seq = 12826 count = 383 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.562500 last_received_ts = 328.562073 last_seq = 12826 current_ts = 328.579132 current_received_ts = 328.578674 current_seq = 12827 count = 384 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.579132 last_received_ts = 328.578674 last_seq = 12827 current_ts = 328.595734 current_received_ts = 328.595306 current_seq = 12828 count = 385 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.595734 last_received_ts = 328.595306 last_seq = 12828 current_ts = 328.612366 current_received_ts = 328.611938 current_seq = 12829 count = 386 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.612366 last_received_ts = 328.611938 last_seq = 12829 current_ts = 328.628998 current_received_ts = 328.628571 current_seq = 12830 count = 387 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.628998 last_received_ts = 328.628571 last_seq = 12830 current_ts = 328.645630 current_received_ts = 328.645172 current_seq = 12831 count = 388 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.645630 last_received_ts = 328.645172 last_seq = 12831 current_ts = 328.662262 current_received_ts = 328.661835 current_seq = 12832 count = 389 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.662262 last_received_ts = 328.661835 last_seq = 12832 current_ts = 328.678894 current_received_ts = 328.678467 current_seq = 12833 count = 390 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.678894 last_received_ts = 328.678467 last_seq = 12833 current_ts = 328.695526 current_received_ts = 328.695068 current_seq = 12834 count = 391 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.695526 last_received_ts = 328.695068 last_seq = 12834 current_ts = 328.712158 current_received_ts = 328.711700 current_seq = 12835 count = 392 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.712158 last_received_ts = 328.711700 last_seq = 12835 current_ts = 328.728790 current_received_ts = 328.728333 current_seq = 12836 count = 393 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.728790 last_received_ts = 328.728333 last_seq = 12836 current_ts = 328.745422 current_received_ts = 328.744965 current_seq = 12837 count = 394 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 34us (kms_flip:2748) DEBUG: name = flip last_ts = 328.745422 last_received_ts = 328.744965 last_seq = 12837 current_ts = 328.762054 current_received_ts = 328.761627 current_seq = 12838 count = 395 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.762054 last_received_ts = 328.761627 last_seq = 12838 current_ts = 328.778656 current_received_ts = 328.778259 current_seq = 12839 count = 396 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.778656 last_received_ts = 328.778259 last_seq = 12839 current_ts = 328.795288 current_received_ts = 328.794861 current_seq = 12840 count = 397 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.795288 last_received_ts = 328.794861 last_seq = 12840 current_ts = 328.811920 current_received_ts = 328.811493 current_seq = 12841 count = 398 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.811920 last_received_ts = 328.811493 last_seq = 12841 current_ts = 328.828552 current_received_ts = 328.828125 current_seq = 12842 count = 399 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.828552 last_received_ts = 328.828125 last_seq = 12842 current_ts = 328.845184 current_received_ts = 328.844727 current_seq = 12843 count = 400 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.845184 last_received_ts = 328.844727 last_seq = 12843 current_ts = 328.861816 current_received_ts = 328.861389 current_seq = 12844 count = 401 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.861816 last_received_ts = 328.861389 last_seq = 12844 current_ts = 328.878448 current_received_ts = 328.878052 current_seq = 12845 count = 402 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.878448 last_received_ts = 328.878052 last_seq = 12845 current_ts = 328.895081 current_received_ts = 328.894653 current_seq = 12846 count = 403 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.895081 last_received_ts = 328.894653 last_seq = 12846 current_ts = 328.911713 current_received_ts = 328.911255 current_seq = 12847 count = 404 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 328.911713 last_received_ts = 328.911255 last_seq = 12847 current_ts = 328.928345 current_received_ts = 328.927887 current_seq = 12848 count = 405 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.928345 last_received_ts = 328.927887 last_seq = 12848 current_ts = 328.944977 current_received_ts = 328.944519 current_seq = 12849 count = 406 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.944977 last_received_ts = 328.944519 last_seq = 12849 current_ts = 328.961609 current_received_ts = 328.961151 current_seq = 12850 count = 407 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.961609 last_received_ts = 328.961151 last_seq = 12850 current_ts = 328.978241 current_received_ts = 328.977783 current_seq = 12851 count = 408 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.978241 last_received_ts = 328.977783 last_seq = 12851 current_ts = 328.994873 current_received_ts = 328.994385 current_seq = 12852 count = 409 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 328.994873 last_received_ts = 328.994385 last_seq = 12852 current_ts = 329.011475 current_received_ts = 329.011047 current_seq = 12853 count = 410 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.011475 last_received_ts = 329.011047 last_seq = 12853 current_ts = 329.028107 current_received_ts = 329.027679 current_seq = 12854 count = 411 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.028107 last_received_ts = 329.027679 last_seq = 12854 current_ts = 329.044739 current_received_ts = 329.044250 current_seq = 12855 count = 412 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.044739 last_received_ts = 329.044250 last_seq = 12855 current_ts = 329.061371 current_received_ts = 329.060944 current_seq = 12856 count = 413 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.061371 last_received_ts = 329.060944 last_seq = 12856 current_ts = 329.078003 current_received_ts = 329.077545 current_seq = 12857 count = 414 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.078003 last_received_ts = 329.077545 last_seq = 12857 current_ts = 329.094635 current_received_ts = 329.094116 current_seq = 12858 count = 415 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 9us (kms_flip:2748) DEBUG: name = flip last_ts = 329.094635 last_received_ts = 329.094116 last_seq = 12858 current_ts = 329.111267 current_received_ts = 329.110840 current_seq = 12859 count = 416 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 329.111267 last_received_ts = 329.110840 last_seq = 12859 current_ts = 329.127899 current_received_ts = 329.127441 current_seq = 12860 count = 417 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 7us (kms_flip:2748) DEBUG: name = flip last_ts = 329.127899 last_received_ts = 329.127441 last_seq = 12860 current_ts = 329.144531 current_received_ts = 329.144104 current_seq = 12861 count = 418 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.144531 last_received_ts = 329.144104 last_seq = 12861 current_ts = 329.161163 current_received_ts = 329.160706 current_seq = 12862 count = 419 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.161163 last_received_ts = 329.160706 last_seq = 12862 current_ts = 329.177795 current_received_ts = 329.177307 current_seq = 12863 count = 420 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.177795 last_received_ts = 329.177307 last_seq = 12863 current_ts = 329.194427 current_received_ts = 329.193970 current_seq = 12864 count = 421 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 35us (kms_flip:2748) DEBUG: name = flip last_ts = 329.194427 last_received_ts = 329.193970 last_seq = 12864 current_ts = 329.211029 current_received_ts = 329.210602 current_seq = 12865 count = 422 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.211029 last_received_ts = 329.210602 last_seq = 12865 current_ts = 329.227661 current_received_ts = 329.227234 current_seq = 12866 count = 423 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.227661 last_received_ts = 329.227234 last_seq = 12866 current_ts = 329.244293 current_received_ts = 329.243835 current_seq = 12867 count = 424 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.244293 last_received_ts = 329.243835 last_seq = 12867 current_ts = 329.260925 current_received_ts = 329.260468 current_seq = 12868 count = 425 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 9us (kms_flip:2748) DEBUG: name = flip last_ts = 329.260925 last_received_ts = 329.260468 last_seq = 12868 current_ts = 329.277557 current_received_ts = 329.277100 current_seq = 12869 count = 426 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.277557 last_received_ts = 329.277100 last_seq = 12869 current_ts = 329.294189 current_received_ts = 329.293732 current_seq = 12870 count = 427 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.294189 last_received_ts = 329.293732 last_seq = 12870 current_ts = 329.310822 current_received_ts = 329.310364 current_seq = 12871 count = 428 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.310822 last_received_ts = 329.310364 last_seq = 12871 current_ts = 329.327454 current_received_ts = 329.327026 current_seq = 12872 count = 429 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.327454 last_received_ts = 329.327026 last_seq = 12872 current_ts = 329.344086 current_received_ts = 329.343567 current_seq = 12873 count = 430 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.344086 last_received_ts = 329.343567 last_seq = 12873 current_ts = 329.360718 current_received_ts = 329.360260 current_seq = 12874 count = 431 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 6us (kms_flip:2748) DEBUG: name = flip last_ts = 329.360718 last_received_ts = 329.360260 last_seq = 12874 current_ts = 329.377350 current_received_ts = 329.376831 current_seq = 12875 count = 432 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.377350 last_received_ts = 329.376831 last_seq = 12875 current_ts = 329.393982 current_received_ts = 329.393524 current_seq = 12876 count = 433 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 8us (kms_flip:2748) DEBUG: name = flip last_ts = 329.393982 last_received_ts = 329.393524 last_seq = 12876 current_ts = 329.410614 current_received_ts = 329.410156 current_seq = 12877 count = 434 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 9us (kms_flip:2748) DEBUG: name = flip last_ts = 329.410614 last_received_ts = 329.410156 last_seq = 12877 current_ts = 329.427216 current_received_ts = 329.426758 current_seq = 12878 count = 435 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 9us (kms_flip:2748) DEBUG: name = flip last_ts = 329.427216 last_received_ts = 329.426758 last_seq = 12878 current_ts = 329.443878 current_received_ts = 329.443329 current_seq = 12879 count = 436 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 6us (kms_flip:2748) DEBUG: name = flip last_ts = 329.443878 last_received_ts = 329.443329 last_seq = 12879 current_ts = 329.460480 current_received_ts = 329.460052 current_seq = 12880 count = 437 seq_step = 1 (kms_flip:2748) DEBUG: Vblank took 674us (kms_flip:2748) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2748) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2748) igt_core-INFO: Stack trace: (kms_flip:2748) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2748) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:2748) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:2748) igt_core-INFO: #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105() (kms_flip:2748) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:2748) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2748) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2748) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A1: FAIL (7.846s)
Dmesg	<6> [321.434472] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1 <7> [321.435015] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:90] <7> [321.435155] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:91] <7> [321.488147] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A] <7> [321.488475] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:72:pipe B] <7> [321.488644] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.enable (expected yes, found no) <7> [321.489214] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.active (expected yes, found no) <7> [321.489789] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1) <7> [321.490244] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in has_pch_encoder (expected yes, found no) <7> [321.490660] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in fdi_lanes (expected 1, found 0) <7> [321.491117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0) <7> [321.491514] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in output_types (expected 0x00000002, found 0x00000000) <7> [321.491985] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [321.492278] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1024, found 0) <7> [321.492514] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 1344, found 0) <7> [321.492768] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1024, found 0) <7> [321.493021] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 1344, found 0) <7> [321.493258] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 1048, found 0) <7> [321.493493] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 1184, found 0) <7> [321.493729] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 768, found 0) <7> [321.493988] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 768, found 0) <7> [321.494242] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 771, found 0) <7> [321.494478] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 777, found 0) <7> [321.494714] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 806, found 0) <7> [321.494978] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 806, found 0) <7> [321.495232] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1024, found 0) <7> [321.495476] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 1344, found 0) <7> [321.495716] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1024, found 0) <7> [321.495967] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 1344, found 0) <7> [321.496229] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 1048, found 0) <7> [321.496464] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 1184, found 0) <7> [321.496698] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 768, found 0) <7> [321.496973] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 768, found 0) <7> [321.497222] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 771, found 0) <7> [321.497458] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 777, found 0) <7> [321.497693] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 806, found 0) <7> [321.497968] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 806, found 0) <7> [321.498218] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [321.498454] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [321.498690] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [321.498945] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [321.499211] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 64800, found 0) <7> [321.499450] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 64800, found 0) <7> [321.499685] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in port_clock (expected 64800, found 0) <7> [321.499949] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:72:pipe B] fastset requirement not met, forcing full modeset <7> [321.500193] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:72:pipe B] releasing PCH DPLL A <7> [321.500447] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:72:pipe B] min cdclk: 72000 kHz -> 0 kHz <7> [321.500680] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:72:pipe B] enable: no [modeset] <7> [321.500958] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:primary B] fb: [NOFB], visible: no <7> [321.501325] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B <7> [321.517414] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found <7> [321.517924] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found <7> [321.518390] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found <7> [321.532635] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x2, on? 1) for [CRTC:72:pipe B] <7> [321.533188] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A <7> [321.533909] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT] <7> [321.534400] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D] <7> [321.534956] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D] <7> [321.535465] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:73:VGA-1] <7> [321.536146] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:72:pipe B] <7> [321.536495] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A] <7> [321.536526] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:76:HDMI-A-1] <7> [321.536628] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [321.536939] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:53:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [321.537172] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3 <7> [321.537412] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [321.537643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [321.537922] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [321.538175] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes) <7> [321.538412] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3) <7> [321.538648] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288) <7> [321.538919] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [321.539176] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [321.539413] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [321.539649] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [321.539905] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [321.540160] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [321.540396] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [321.540632] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [321.540892] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [321.541146] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [321.541385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [321.541643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [321.541913] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [321.542155] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [321.542385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [321.542614] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [321.542876] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [321.543144] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [321.543374] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [321.543603] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [321.543873] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [321.544135] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [321.544381] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [321.544610] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [321.544890] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [321.545140] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [321.545369] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [321.545598] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [321.545859] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [321.546106] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [321.546335] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [321.546564] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_infoframe (expected no, found yes) <7> [321.546826] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in dpll_hw_state <7> [321.547091] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [321.547320] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09 <7> [321.547549] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [321.547812] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06 <7> [321.548096] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [321.548326] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800) <7> [321.548565] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800) <7> [321.548841] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in port_clock (expected 0, found 223200) <7> [321.549085] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [321.549315] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [321.549553] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in avi infoframe <7> [321.549814] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [321.550065] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [321.550294] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [321.550296] i915 0000:00:02.0: colorspace: RGB <7> [321.550299] i915 0000:00:02.0: scan mode: Underscan <7> [321.550301] i915 0000:00:02.0: colorimetry: No Data <7> [321.550303] i915 0000:00:02.0: picture aspect: No Data <7> [321.550305] i915 0000:00:02.0: active aspect: Same as Picture <7> [321.550306] i915 0000:00:02.0: itc: No Data <7> [321.550308] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [321.550310] i915 0000:00:02.0: quantization range: Full <7> [321.550312] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [321.550314] i915 0000:00:02.0: video code: 0 <7> [321.550316] i915 0000:00:02.0: ycc quantization range: Full <7> [321.550318] i915 0000:00:02.0: hdmi content type: Graphics <7> [321.550320] i915 0000:00:02.0: pixel repeat: 0 <7> [321.550322] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [321.550324] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in spd infoframe <7> [321.550552] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [321.550871] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [321.551138] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [321.551141] i915 0000:00:02.0: vendor: Intel <7> [321.551143] i915 0000:00:02.0: product: Integrated gfx <7> [321.551145] i915 0000:00:02.0: source device information: PC General (0x9) <7> [321.551148] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hdmi infoframe <7> [321.551385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [321.551611] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [321.551876] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [321.551881] i915 0000:00:02.0: empty frame <7> [321.551885] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:53:pipe A] fastset requirement not met, forcing full modeset <7> [321.552170] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:53:pipe A] min cdclk: 0 kHz -> 165334 kHz <7> [321.552411] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:53:pipe A] allocated PCH DPLL A <7> [321.552644] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:53:pipe A] reserving PCH DPLL A <7> [321.552927] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:53:pipe A] enable: yes [modeset] <7> [321.553168] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [321.553396] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0 <7> [321.553624] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [321.553909] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on <7> [321.553901] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [321.554159] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [321.554394] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [321.554622] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64 <7> [321.554937] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [321.555208] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [321.555436] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [321.555438] i915 0000:00:02.0: colorspace: RGB <7> [321.555440] i915 0000:00:02.0: scan mode: Underscan <7> [321.555442] i915 0000:00:02.0: colorimetry: No Data <7> [321.555444] i915 0000:00:02.0: picture aspect: No Data <7> [321.555446] i915 0000:00:02.0: active aspect: Same as Picture <7> [321.555448] i915 0000:00:02.0: itc: No Data <7> [321.555450] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [321.555452] i915 0000:00:02.0: quantization range: Full <7> [321.555453] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [321.555455] i915 0000:00:02.0: video code: 0 <7> [321.555457] i915 0000:00:02.0: ycc quantization range: Full <7> [321.555459] i915 0000:00:02.0: hdmi content type: Graphics <7> [321.555461] i915 0000:00:02.0: pixel repeat: 0 <7> [321.555463] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [321.555465] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [321.555467] i915 0000:00:02.0: vendor: Intel <7> [321.555469] i915 0000:00:02.0: product: Integrated gfx <7> [321.555471] i915 0000:00:02.0: source device information: PC General (0x9) <7> [321.555474] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [321.555476] i915 0000:00:02.0: empty frame <7> [321.555478] 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> [321.555706] 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> [321.555976] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1 <7> [321.556245] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [321.556479] 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> [321.556714] 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> [321.556993] 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> [321.557242] 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> [321.557478] 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> [321.557714] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [321.557966] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [321.558221] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [321.558457] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pixel rate 148800, min cdclk 165334, min voltage level 0 <7> [321.558691] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0 <7> [321.558951] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [321.559202] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [321.559441] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [321.559669] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [321.559944] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06 <7> [321.560239] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [321.560467] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [321.560695] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [321.560968] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [321.561212] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [321.561440] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [321.561678] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:primary A] fb: [FB:90] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [321.561949] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [321.562215] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [321.564665] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on <7> [321.564956] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT] <7> [321.565181] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D] <7> [321.565416] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D] <7> [321.566242] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [321.567328] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100 <7> [321.567555] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done. <7> [321.568505] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x200 <7> [321.568743] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done. <7> [321.568999] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done. <7> [321.569242] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:53:pipe A] <7> [321.569469] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A <7> [321.621172] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:76:HDMI-A-1][ENCODER:75:HDMI D] Enable audio codec on [CRTC:53:pipe A], 32 bytes ELD <7> [321.637831] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults <7> [321.638334] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000) <7> [321.638873] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:76:HDMI-A-1] <7> [321.639384] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:53:pipe A] <6> [329.282306] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL

Detail

Value

Duration

7.85 seconds

Hostname

shard-snb6

Igt-Version

IGT-Version: 2.4-g1aba4b364 (x86_64) (Linux: 7.0.0-CI_DRM_18357-g95fbbe4877e1+ x86_64)

Out

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

Err

Starting dynamic subtest: A-HDMI-A1
(kms_flip:2748) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2748) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-HDMI-A1 failed.
**** DEBUG ****
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.431702
last_received_ts = 327.431305
last_seq = 12758
current_ts = 327.448334
current_received_ts = 327.447937
current_seq = 12759
count = 316
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.448334
last_received_ts = 327.447937
last_seq = 12759
current_ts = 327.464966
current_received_ts = 327.464508
current_seq = 12760
count = 317
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.464966
last_received_ts = 327.464508
last_seq = 12760
current_ts = 327.481567
current_received_ts = 327.481140
current_seq = 12761
count = 318
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.481567
last_received_ts = 327.481140
last_seq = 12761
current_ts = 327.498199
current_received_ts = 327.497742
current_seq = 12762
count = 319
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.498199
last_received_ts = 327.497742
last_seq = 12762
current_ts = 327.514832
current_received_ts = 327.514374
current_seq = 12763
count = 320
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.514832
last_received_ts = 327.514374
last_seq = 12763
current_ts = 327.531464
current_received_ts = 327.531036
current_seq = 12764
count = 321
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.531464
last_received_ts = 327.531036
last_seq = 12764
current_ts = 327.548096
current_received_ts = 327.547668
current_seq = 12765
count = 322
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.548096
last_received_ts = 327.547668
last_seq = 12765
current_ts = 327.564728
current_received_ts = 327.564270
current_seq = 12766
count = 323
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 5us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.564728
last_received_ts = 327.564270
last_seq = 12766
current_ts = 327.581360
current_received_ts = 327.580933
current_seq = 12767
count = 324
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.581360
last_received_ts = 327.580933
last_seq = 12767
current_ts = 327.597992
current_received_ts = 327.597565
current_seq = 12768
count = 325
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.597992
last_received_ts = 327.597565
last_seq = 12768
current_ts = 327.614624
current_received_ts = 327.614166
current_seq = 12769
count = 326
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.614624
last_received_ts = 327.614166
last_seq = 12769
current_ts = 327.631256
current_received_ts = 327.630829
current_seq = 12770
count = 327
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.631256
last_received_ts = 327.630829
last_seq = 12770
current_ts = 327.647888
current_received_ts = 327.647461
current_seq = 12771
count = 328
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.647888
last_received_ts = 327.647461
last_seq = 12771
current_ts = 327.664520
current_received_ts = 327.664093
current_seq = 12772
count = 329
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.664520
last_received_ts = 327.664093
last_seq = 12772
current_ts = 327.681122
current_received_ts = 327.680664
current_seq = 12773
count = 330
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.681122
last_received_ts = 327.680664
last_seq = 12773
current_ts = 327.697754
current_received_ts = 327.697296
current_seq = 12774
count = 331
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.697754
last_received_ts = 327.697296
last_seq = 12774
current_ts = 327.714386
current_received_ts = 327.713928
current_seq = 12775
count = 332
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.714386
last_received_ts = 327.713928
last_seq = 12775
current_ts = 327.731018
current_received_ts = 327.730560
current_seq = 12776
count = 333
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.731018
last_received_ts = 327.730560
last_seq = 12776
current_ts = 327.747650
current_received_ts = 327.747192
current_seq = 12777
count = 334
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.747650
last_received_ts = 327.747192
last_seq = 12777
current_ts = 327.764282
current_received_ts = 327.763824
current_seq = 12778
count = 335
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 6us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.764282
last_received_ts = 327.763824
last_seq = 12778
current_ts = 327.780914
current_received_ts = 327.780457
current_seq = 12779
count = 336
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.780914
last_received_ts = 327.780457
last_seq = 12779
current_ts = 327.797546
current_received_ts = 327.797089
current_seq = 12780
count = 337
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.797546
last_received_ts = 327.797089
last_seq = 12780
current_ts = 327.814178
current_received_ts = 327.813721
current_seq = 12781
count = 338
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.814178
last_received_ts = 327.813721
last_seq = 12781
current_ts = 327.830811
current_received_ts = 327.830353
current_seq = 12782
count = 339
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.830811
last_received_ts = 327.830353
last_seq = 12782
current_ts = 327.847412
current_received_ts = 327.846954
current_seq = 12783
count = 340
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.847412
last_received_ts = 327.846954
last_seq = 12783
current_ts = 327.864044
current_received_ts = 327.863617
current_seq = 12784
count = 341
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.864044
last_received_ts = 327.863617
last_seq = 12784
current_ts = 327.880676
current_received_ts = 327.880249
current_seq = 12785
count = 342
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.880676
last_received_ts = 327.880249
last_seq = 12785
current_ts = 327.897308
current_received_ts = 327.896881
current_seq = 12786
count = 343
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.897308
last_received_ts = 327.896881
last_seq = 12786
current_ts = 327.913940
current_received_ts = 327.913513
current_seq = 12787
count = 344
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.913940
last_received_ts = 327.913513
last_seq = 12787
current_ts = 327.930573
current_received_ts = 327.930145
current_seq = 12788
count = 345
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.930573
last_received_ts = 327.930145
last_seq = 12788
current_ts = 327.947205
current_received_ts = 327.946747
current_seq = 12789
count = 346
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.947205
last_received_ts = 327.946747
last_seq = 12789
current_ts = 327.963837
current_received_ts = 327.963409
current_seq = 12790
count = 347
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.963837
last_received_ts = 327.963409
last_seq = 12790
current_ts = 327.980469
current_received_ts = 327.980042
current_seq = 12791
count = 348
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.980469
last_received_ts = 327.980042
last_seq = 12791
current_ts = 327.997101
current_received_ts = 327.996643
current_seq = 12792
count = 349
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 327.997101
last_received_ts = 327.996643
last_seq = 12792
current_ts = 328.013733
current_received_ts = 328.013275
current_seq = 12793
count = 350
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.013733
last_received_ts = 328.013275
last_seq = 12793
current_ts = 328.030334
current_received_ts = 328.029907
current_seq = 12794
count = 351
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.030334
last_received_ts = 328.029907
last_seq = 12794
current_ts = 328.046967
current_received_ts = 328.046539
current_seq = 12795
count = 352
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.046967
last_received_ts = 328.046539
last_seq = 12795
current_ts = 328.063599
current_received_ts = 328.063171
current_seq = 12796
count = 353
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.063599
last_received_ts = 328.063171
last_seq = 12796
current_ts = 328.080231
current_received_ts = 328.079803
current_seq = 12797
count = 354
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.080231
last_received_ts = 328.079803
last_seq = 12797
current_ts = 328.096863
current_received_ts = 328.096405
current_seq = 12798
count = 355
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.096863
last_received_ts = 328.096405
last_seq = 12798
current_ts = 328.113495
current_received_ts = 328.113068
current_seq = 12799
count = 356
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.113495
last_received_ts = 328.113068
last_seq = 12799
current_ts = 328.130127
current_received_ts = 328.129669
current_seq = 12800
count = 357
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.130127
last_received_ts = 328.129669
last_seq = 12800
current_ts = 328.146759
current_received_ts = 328.146301
current_seq = 12801
count = 358
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.146759
last_received_ts = 328.146301
last_seq = 12801
current_ts = 328.163391
current_received_ts = 328.162964
current_seq = 12802
count = 359
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.163391
last_received_ts = 328.162964
last_seq = 12802
current_ts = 328.180023
current_received_ts = 328.179565
current_seq = 12803
count = 360
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.180023
last_received_ts = 328.179565
last_seq = 12803
current_ts = 328.196655
current_received_ts = 328.196198
current_seq = 12804
count = 361
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.196655
last_received_ts = 328.196198
last_seq = 12804
current_ts = 328.213257
current_received_ts = 328.212830
current_seq = 12805
count = 362
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.213257
last_received_ts = 328.212830
last_seq = 12805
current_ts = 328.229889
current_received_ts = 328.229462
current_seq = 12806
count = 363
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.229889
last_received_ts = 328.229462
last_seq = 12806
current_ts = 328.246521
current_received_ts = 328.246124
current_seq = 12807
count = 364
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.246521
last_received_ts = 328.246124
last_seq = 12807
current_ts = 328.263153
current_received_ts = 328.262726
current_seq = 12808
count = 365
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.263153
last_received_ts = 328.262726
last_seq = 12808
current_ts = 328.279785
current_received_ts = 328.279266
current_seq = 12809
count = 366
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.279785
last_received_ts = 328.279266
last_seq = 12809
current_ts = 328.296417
current_received_ts = 328.295990
current_seq = 12810
count = 367
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.296417
last_received_ts = 328.295990
last_seq = 12810
current_ts = 328.313049
current_received_ts = 328.312622
current_seq = 12811
count = 368
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.313049
last_received_ts = 328.312622
last_seq = 12811
current_ts = 328.329681
current_received_ts = 328.329254
current_seq = 12812
count = 369
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.329681
last_received_ts = 328.329254
last_seq = 12812
current_ts = 328.346313
current_received_ts = 328.345825
current_seq = 12813
count = 370
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.346313
last_received_ts = 328.345825
last_seq = 12813
current_ts = 328.362946
current_received_ts = 328.362488
current_seq = 12814
count = 371
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.362946
last_received_ts = 328.362488
last_seq = 12814
current_ts = 328.379578
current_received_ts = 328.379120
current_seq = 12815
count = 372
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.379578
last_received_ts = 328.379120
last_seq = 12815
current_ts = 328.396210
current_received_ts = 328.395752
current_seq = 12816
count = 373
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.396210
last_received_ts = 328.395752
last_seq = 12816
current_ts = 328.412811
current_received_ts = 328.412384
current_seq = 12817
count = 374
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.412811
last_received_ts = 328.412384
last_seq = 12817
current_ts = 328.429443
current_received_ts = 328.429047
current_seq = 12818
count = 375
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 17us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.429443
last_received_ts = 328.429047
last_seq = 12818
current_ts = 328.446075
current_received_ts = 328.445618
current_seq = 12819
count = 376
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 9us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.446075
last_received_ts = 328.445618
last_seq = 12819
current_ts = 328.462708
current_received_ts = 328.462250
current_seq = 12820
count = 377
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 9us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.462708
last_received_ts = 328.462250
last_seq = 12820
current_ts = 328.479340
current_received_ts = 328.478912
current_seq = 12821
count = 378
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.479340
last_received_ts = 328.478912
last_seq = 12821
current_ts = 328.495972
current_received_ts = 328.495514
current_seq = 12822
count = 379
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.495972
last_received_ts = 328.495514
last_seq = 12822
current_ts = 328.512604
current_received_ts = 328.512146
current_seq = 12823
count = 380
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.512604
last_received_ts = 328.512146
last_seq = 12823
current_ts = 328.529236
current_received_ts = 328.528778
current_seq = 12824
count = 381
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 9us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.529236
last_received_ts = 328.528778
last_seq = 12824
current_ts = 328.545868
current_received_ts = 328.545410
current_seq = 12825
count = 382
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.545868
last_received_ts = 328.545410
last_seq = 12825
current_ts = 328.562500
current_received_ts = 328.562073
current_seq = 12826
count = 383
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.562500
last_received_ts = 328.562073
last_seq = 12826
current_ts = 328.579132
current_received_ts = 328.578674
current_seq = 12827
count = 384
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.579132
last_received_ts = 328.578674
last_seq = 12827
current_ts = 328.595734
current_received_ts = 328.595306
current_seq = 12828
count = 385
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.595734
last_received_ts = 328.595306
last_seq = 12828
current_ts = 328.612366
current_received_ts = 328.611938
current_seq = 12829
count = 386
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.612366
last_received_ts = 328.611938
last_seq = 12829
current_ts = 328.628998
current_received_ts = 328.628571
current_seq = 12830
count = 387
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.628998
last_received_ts = 328.628571
last_seq = 12830
current_ts = 328.645630
current_received_ts = 328.645172
current_seq = 12831
count = 388
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.645630
last_received_ts = 328.645172
last_seq = 12831
current_ts = 328.662262
current_received_ts = 328.661835
current_seq = 12832
count = 389
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.662262
last_received_ts = 328.661835
last_seq = 12832
current_ts = 328.678894
current_received_ts = 328.678467
current_seq = 12833
count = 390
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.678894
last_received_ts = 328.678467
last_seq = 12833
current_ts = 328.695526
current_received_ts = 328.695068
current_seq = 12834
count = 391
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.695526
last_received_ts = 328.695068
last_seq = 12834
current_ts = 328.712158
current_received_ts = 328.711700
current_seq = 12835
count = 392
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.712158
last_received_ts = 328.711700
last_seq = 12835
current_ts = 328.728790
current_received_ts = 328.728333
current_seq = 12836
count = 393
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.728790
last_received_ts = 328.728333
last_seq = 12836
current_ts = 328.745422
current_received_ts = 328.744965
current_seq = 12837
count = 394
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 34us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.745422
last_received_ts = 328.744965
last_seq = 12837
current_ts = 328.762054
current_received_ts = 328.761627
current_seq = 12838
count = 395
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.762054
last_received_ts = 328.761627
last_seq = 12838
current_ts = 328.778656
current_received_ts = 328.778259
current_seq = 12839
count = 396
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.778656
last_received_ts = 328.778259
last_seq = 12839
current_ts = 328.795288
current_received_ts = 328.794861
current_seq = 12840
count = 397
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.795288
last_received_ts = 328.794861
last_seq = 12840
current_ts = 328.811920
current_received_ts = 328.811493
current_seq = 12841
count = 398
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.811920
last_received_ts = 328.811493
last_seq = 12841
current_ts = 328.828552
current_received_ts = 328.828125
current_seq = 12842
count = 399
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.828552
last_received_ts = 328.828125
last_seq = 12842
current_ts = 328.845184
current_received_ts = 328.844727
current_seq = 12843
count = 400
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.845184
last_received_ts = 328.844727
last_seq = 12843
current_ts = 328.861816
current_received_ts = 328.861389
current_seq = 12844
count = 401
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.861816
last_received_ts = 328.861389
last_seq = 12844
current_ts = 328.878448
current_received_ts = 328.878052
current_seq = 12845
count = 402
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.878448
last_received_ts = 328.878052
last_seq = 12845
current_ts = 328.895081
current_received_ts = 328.894653
current_seq = 12846
count = 403
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.895081
last_received_ts = 328.894653
last_seq = 12846
current_ts = 328.911713
current_received_ts = 328.911255
current_seq = 12847
count = 404
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.911713
last_received_ts = 328.911255
last_seq = 12847
current_ts = 328.928345
current_received_ts = 328.927887
current_seq = 12848
count = 405
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.928345
last_received_ts = 328.927887
last_seq = 12848
current_ts = 328.944977
current_received_ts = 328.944519
current_seq = 12849
count = 406
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.944977
last_received_ts = 328.944519
last_seq = 12849
current_ts = 328.961609
current_received_ts = 328.961151
current_seq = 12850
count = 407
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.961609
last_received_ts = 328.961151
last_seq = 12850
current_ts = 328.978241
current_received_ts = 328.977783
current_seq = 12851
count = 408
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.978241
last_received_ts = 328.977783
last_seq = 12851
current_ts = 328.994873
current_received_ts = 328.994385
current_seq = 12852
count = 409
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 328.994873
last_received_ts = 328.994385
last_seq = 12852
current_ts = 329.011475
current_received_ts = 329.011047
current_seq = 12853
count = 410
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.011475
last_received_ts = 329.011047
last_seq = 12853
current_ts = 329.028107
current_received_ts = 329.027679
current_seq = 12854
count = 411
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.028107
last_received_ts = 329.027679
last_seq = 12854
current_ts = 329.044739
current_received_ts = 329.044250
current_seq = 12855
count = 412
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.044739
last_received_ts = 329.044250
last_seq = 12855
current_ts = 329.061371
current_received_ts = 329.060944
current_seq = 12856
count = 413
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.061371
last_received_ts = 329.060944
last_seq = 12856
current_ts = 329.078003
current_received_ts = 329.077545
current_seq = 12857
count = 414
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.078003
last_received_ts = 329.077545
last_seq = 12857
current_ts = 329.094635
current_received_ts = 329.094116
current_seq = 12858
count = 415
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 9us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.094635
last_received_ts = 329.094116
last_seq = 12858
current_ts = 329.111267
current_received_ts = 329.110840
current_seq = 12859
count = 416
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.111267
last_received_ts = 329.110840
last_seq = 12859
current_ts = 329.127899
current_received_ts = 329.127441
current_seq = 12860
count = 417
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 7us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.127899
last_received_ts = 329.127441
last_seq = 12860
current_ts = 329.144531
current_received_ts = 329.144104
current_seq = 12861
count = 418
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.144531
last_received_ts = 329.144104
last_seq = 12861
current_ts = 329.161163
current_received_ts = 329.160706
current_seq = 12862
count = 419
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.161163
last_received_ts = 329.160706
last_seq = 12862
current_ts = 329.177795
current_received_ts = 329.177307
current_seq = 12863
count = 420
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.177795
last_received_ts = 329.177307
last_seq = 12863
current_ts = 329.194427
current_received_ts = 329.193970
current_seq = 12864
count = 421
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 35us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.194427
last_received_ts = 329.193970
last_seq = 12864
current_ts = 329.211029
current_received_ts = 329.210602
current_seq = 12865
count = 422
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.211029
last_received_ts = 329.210602
last_seq = 12865
current_ts = 329.227661
current_received_ts = 329.227234
current_seq = 12866
count = 423
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.227661
last_received_ts = 329.227234
last_seq = 12866
current_ts = 329.244293
current_received_ts = 329.243835
current_seq = 12867
count = 424
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.244293
last_received_ts = 329.243835
last_seq = 12867
current_ts = 329.260925
current_received_ts = 329.260468
current_seq = 12868
count = 425
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 9us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.260925
last_received_ts = 329.260468
last_seq = 12868
current_ts = 329.277557
current_received_ts = 329.277100
current_seq = 12869
count = 426
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.277557
last_received_ts = 329.277100
last_seq = 12869
current_ts = 329.294189
current_received_ts = 329.293732
current_seq = 12870
count = 427
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.294189
last_received_ts = 329.293732
last_seq = 12870
current_ts = 329.310822
current_received_ts = 329.310364
current_seq = 12871
count = 428
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.310822
last_received_ts = 329.310364
last_seq = 12871
current_ts = 329.327454
current_received_ts = 329.327026
current_seq = 12872
count = 429
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.327454
last_received_ts = 329.327026
last_seq = 12872
current_ts = 329.344086
current_received_ts = 329.343567
current_seq = 12873
count = 430
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.344086
last_received_ts = 329.343567
last_seq = 12873
current_ts = 329.360718
current_received_ts = 329.360260
current_seq = 12874
count = 431
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 6us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.360718
last_received_ts = 329.360260
last_seq = 12874
current_ts = 329.377350
current_received_ts = 329.376831
current_seq = 12875
count = 432
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.377350
last_received_ts = 329.376831
last_seq = 12875
current_ts = 329.393982
current_received_ts = 329.393524
current_seq = 12876
count = 433
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 8us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.393982
last_received_ts = 329.393524
last_seq = 12876
current_ts = 329.410614
current_received_ts = 329.410156
current_seq = 12877
count = 434
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 9us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.410614
last_received_ts = 329.410156
last_seq = 12877
current_ts = 329.427216
current_received_ts = 329.426758
current_seq = 12878
count = 435
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 9us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.427216
last_received_ts = 329.426758
last_seq = 12878
current_ts = 329.443878
current_received_ts = 329.443329
current_seq = 12879
count = 436
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 6us
(kms_flip:2748) DEBUG: name = flip
last_ts = 329.443878
last_received_ts = 329.443329
last_seq = 12879
current_ts = 329.460480
current_received_ts = 329.460052
current_seq = 12880
count = 437
seq_step = 1
(kms_flip:2748) DEBUG: Vblank took 674us
(kms_flip:2748) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2748) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2748) igt_core-INFO: Stack trace:
(kms_flip:2748) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2748) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2748) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2748) igt_core-INFO:   #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
(kms_flip:2748) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2748) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2748) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2748) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A1: FAIL (7.846s)

Dmesg

<6> [321.434472] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1

<7> [321.435015] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:90]

<7> [321.435155] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:91]

<7> [321.488147] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A]

<7> [321.488475] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:72:pipe B]

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

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

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

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

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

<7> [321.491117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [321.500193] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:72:pipe B] releasing PCH DPLL A

<7> [321.500447] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:72:pipe B] min cdclk: 72000 kHz -> 0 kHz

<7> [321.500680] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:72:pipe B] enable: no [modeset]

<7> [321.500958] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:primary B] fb: [NOFB], visible: no

<7> [321.501325] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B

<7> [321.517414] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found

<7> [321.517924] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found

<7> [321.518390] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found

<7> [321.532635] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x2, on? 1) for [CRTC:72:pipe B]

<7> [321.533188] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A

<7> [321.533909] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT]

<7> [321.534400] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D]

<7> [321.534956] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D]

<7> [321.535465] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:73:VGA-1]

<7> [321.536146] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:72:pipe B]

<7> [321.536495] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A]

<7> [321.536526] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:76:HDMI-A-1]

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

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

<7> [321.537172] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3

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

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

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

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

<7> [321.538412] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3)

<7> [321.538648] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [321.546826] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in dpll_hw_state

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

<7> [321.547320] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09

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

<7> [321.547812] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [321.552170] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:53:pipe A] min cdclk: 0 kHz -> 165334 kHz

<7> [321.552411] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:53:pipe A] allocated PCH DPLL A

<7> [321.552644] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:53:pipe A] reserving PCH DPLL A

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

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

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

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

<7> [321.553909] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on

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

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

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

<7> [321.554622] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [321.555478] 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> [321.555706] 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> [321.555976] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1

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

<7> [321.556479] 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> [321.556714] 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> [321.556993] 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> [321.557242] 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> [321.557478] 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> [321.557714] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9

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

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

<7> [321.558457] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pixel rate 148800, min cdclk 165334, min voltage level 0

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

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

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

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

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

<7> [321.559944] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06

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

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

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

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

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

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

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

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

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

<7> [321.564665] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on

<7> [321.564956] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT]

<7> [321.565181] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D]

<7> [321.565416] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D]

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

<7> [321.567328] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100

<7> [321.567555] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done.

<7> [321.568505] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x200

<7> [321.568743] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done.

<7> [321.568999] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done.

<7> [321.569242] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:53:pipe A]

<7> [321.569469] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A

<7> [321.621172] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:76:HDMI-A-1][ENCODER:75:HDMI D] Enable audio codec on [CRTC:53:pipe A], 32 bytes ELD

<7> [321.637831] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults

<7> [321.638334] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000)

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

<7> [321.639384] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:53:pipe A]

<6> [329.282306] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL

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