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

Detail	Value
Duration	4.06 seconds
Hostname	shard-glk6
Igt-Version	IGT-Version: 2.2-g3a460cb78 (x86_64) (Linux: 6.18.0-CI_DRM_17613-g4ee45005b554+ x86_64)
Out	Starting dynamic subtest: B-HDMI-A2 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1889 run_test() #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045() #4 ../tests/kms_flip.c:2045 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest B-HDMI-A2: FAIL (4.061s)
Err	Starting dynamic subtest: B-HDMI-A2 (kms_flip:2509) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2509) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest B-HDMI-A2 failed. ** DEBUG (kms_flip:2509) DEBUG: name = flip last_ts = 503.677734 last_received_ts = 503.677612 last_seq = 12441 current_ts = 503.694427 current_received_ts = 503.694275 current_seq = 12442 count = 58 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 503.694427 last_received_ts = 503.694275 last_seq = 12442 current_ts = 503.711090 current_received_ts = 503.710907 current_seq = 12443 count = 59 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 21us (kms_flip:2509) DEBUG: name = flip last_ts = 503.711090 last_received_ts = 503.710907 last_seq = 12443 current_ts = 503.727753 current_received_ts = 503.727661 current_seq = 12444 count = 60 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 503.727753 last_received_ts = 503.727661 last_seq = 12444 current_ts = 503.744415 current_received_ts = 503.744293 current_seq = 12445 count = 61 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 503.744415 last_received_ts = 503.744293 last_seq = 12445 current_ts = 503.761078 current_received_ts = 503.760956 current_seq = 12446 count = 62 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 20us (kms_flip:2509) DEBUG: name = flip last_ts = 503.761078 last_received_ts = 503.760956 last_seq = 12446 current_ts = 503.777740 current_received_ts = 503.777679 current_seq = 12447 count = 63 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 503.777740 last_received_ts = 503.777679 last_seq = 12447 current_ts = 503.794434 current_received_ts = 503.794342 current_seq = 12448 count = 64 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 503.794434 last_received_ts = 503.794342 last_seq = 12448 current_ts = 503.811096 current_received_ts = 503.810974 current_seq = 12449 count = 65 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 27us (kms_flip:2509) DEBUG: name = flip last_ts = 503.811096 last_received_ts = 503.810974 last_seq = 12449 current_ts = 503.827759 current_received_ts = 503.827637 current_seq = 12450 count = 66 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 503.827759 last_received_ts = 503.827637 last_seq = 12450 current_ts = 503.844421 current_received_ts = 503.844330 current_seq = 12451 count = 67 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 27us (kms_flip:2509) DEBUG: name = flip last_ts = 503.844421 last_received_ts = 503.844330 last_seq = 12451 current_ts = 503.861084 current_received_ts = 503.860931 current_seq = 12452 count = 68 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 84us (kms_flip:2509) DEBUG: name = flip last_ts = 503.861084 last_received_ts = 503.860931 last_seq = 12452 current_ts = 503.877747 current_received_ts = 503.877686 current_seq = 12453 count = 69 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 503.877747 last_received_ts = 503.877686 last_seq = 12453 current_ts = 503.894409 current_received_ts = 503.894348 current_seq = 12454 count = 70 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 503.894409 last_received_ts = 503.894348 last_seq = 12454 current_ts = 503.911072 current_received_ts = 503.910950 current_seq = 12455 count = 71 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 17us (kms_flip:2509) DEBUG: name = flip last_ts = 503.911072 last_received_ts = 503.910950 last_seq = 12455 current_ts = 503.927765 current_received_ts = 503.927643 current_seq = 12456 count = 72 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 503.927765 last_received_ts = 503.927643 last_seq = 12456 current_ts = 503.944427 current_received_ts = 503.944336 current_seq = 12457 count = 73 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 503.944427 last_received_ts = 503.944336 last_seq = 12457 current_ts = 503.961090 current_received_ts = 503.960968 current_seq = 12458 count = 74 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 503.961090 last_received_ts = 503.960968 last_seq = 12458 current_ts = 503.977753 current_received_ts = 503.977631 current_seq = 12459 count = 75 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 503.977753 last_received_ts = 503.977631 last_seq = 12459 current_ts = 503.994415 current_received_ts = 503.994324 current_seq = 12460 count = 76 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 503.994415 last_received_ts = 503.994324 last_seq = 12460 current_ts = 504.011078 current_received_ts = 504.010895 current_seq = 12461 count = 77 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.011078 last_received_ts = 504.010895 last_seq = 12461 current_ts = 504.027740 current_received_ts = 504.027679 current_seq = 12462 count = 78 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.027740 last_received_ts = 504.027679 last_seq = 12462 current_ts = 504.044434 current_received_ts = 504.044342 current_seq = 12463 count = 79 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.044434 last_received_ts = 504.044342 last_seq = 12463 current_ts = 504.061096 current_received_ts = 504.060974 current_seq = 12464 count = 80 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 21us (kms_flip:2509) DEBUG: name = flip last_ts = 504.061096 last_received_ts = 504.060974 last_seq = 12464 current_ts = 504.077759 current_received_ts = 504.077667 current_seq = 12465 count = 81 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.077759 last_received_ts = 504.077667 last_seq = 12465 current_ts = 504.094421 current_received_ts = 504.094299 current_seq = 12466 count = 82 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.094421 last_received_ts = 504.094299 last_seq = 12466 current_ts = 504.111084 current_received_ts = 504.111084 current_seq = 12467 count = 83 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 27us (kms_flip:2509) DEBUG: name = flip last_ts = 504.111084 last_received_ts = 504.111084 last_seq = 12467 current_ts = 504.127747 current_received_ts = 504.127594 current_seq = 12468 count = 84 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.127747 last_received_ts = 504.127594 last_seq = 12468 current_ts = 504.144409 current_received_ts = 504.144287 current_seq = 12469 count = 85 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.144409 last_received_ts = 504.144287 last_seq = 12469 current_ts = 504.161102 current_received_ts = 504.160980 current_seq = 12470 count = 86 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.161102 last_received_ts = 504.160980 last_seq = 12470 current_ts = 504.177765 current_received_ts = 504.177643 current_seq = 12471 count = 87 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.177765 last_received_ts = 504.177643 last_seq = 12471 current_ts = 504.194427 current_received_ts = 504.194305 current_seq = 12472 count = 88 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.194427 last_received_ts = 504.194305 last_seq = 12472 current_ts = 504.211090 current_received_ts = 504.210938 current_seq = 12473 count = 89 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 90us (kms_flip:2509) DEBUG: name = flip last_ts = 504.211090 last_received_ts = 504.210938 last_seq = 12473 current_ts = 504.227753 current_received_ts = 504.227661 current_seq = 12474 count = 90 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.227753 last_received_ts = 504.227661 last_seq = 12474 current_ts = 504.244415 current_received_ts = 504.244171 current_seq = 12475 count = 91 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.244415 last_received_ts = 504.244171 last_seq = 12475 current_ts = 504.261078 current_received_ts = 504.260956 current_seq = 12476 count = 92 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.261078 last_received_ts = 504.260956 last_seq = 12476 current_ts = 504.277740 current_received_ts = 504.277618 current_seq = 12477 count = 93 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.277740 last_received_ts = 504.277618 last_seq = 12477 current_ts = 504.294403 current_received_ts = 504.294220 current_seq = 12478 count = 94 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 22us (kms_flip:2509) DEBUG: name = flip last_ts = 504.294403 last_received_ts = 504.294220 last_seq = 12478 current_ts = 504.311066 current_received_ts = 504.310913 current_seq = 12479 count = 95 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 98us (kms_flip:2509) DEBUG: name = flip last_ts = 504.311066 last_received_ts = 504.310913 last_seq = 12479 current_ts = 504.327759 current_received_ts = 504.327637 current_seq = 12480 count = 96 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.327759 last_received_ts = 504.327637 last_seq = 12480 current_ts = 504.344421 current_received_ts = 504.344055 current_seq = 12481 count = 97 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 504.344421 last_received_ts = 504.344055 last_seq = 12481 current_ts = 504.361084 current_received_ts = 504.360931 current_seq = 12482 count = 98 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.361084 last_received_ts = 504.360931 last_seq = 12482 current_ts = 504.377747 current_received_ts = 504.377594 current_seq = 12483 count = 99 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 22us (kms_flip:2509) DEBUG: name = flip last_ts = 504.377747 last_received_ts = 504.377594 last_seq = 12483 current_ts = 504.394409 current_received_ts = 504.393982 current_seq = 12484 count = 100 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.394409 last_received_ts = 504.393982 last_seq = 12484 current_ts = 504.411072 current_received_ts = 504.410919 current_seq = 12485 count = 101 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 109us (kms_flip:2509) DEBUG: name = flip last_ts = 504.411072 last_received_ts = 504.410919 last_seq = 12485 current_ts = 504.427765 current_received_ts = 504.427582 current_seq = 12486 count = 102 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 504.427765 last_received_ts = 504.427582 last_seq = 12486 current_ts = 504.444427 current_received_ts = 504.444275 current_seq = 12487 count = 103 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.444427 last_received_ts = 504.444275 last_seq = 12487 current_ts = 504.461090 current_received_ts = 504.460938 current_seq = 12488 count = 104 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 81us (kms_flip:2509) DEBUG: name = flip last_ts = 504.461090 last_received_ts = 504.460938 last_seq = 12488 current_ts = 504.477753 current_received_ts = 504.477631 current_seq = 12489 count = 105 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.477753 last_received_ts = 504.477631 last_seq = 12489 current_ts = 504.494415 current_received_ts = 504.494141 current_seq = 12490 count = 106 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.494415 last_received_ts = 504.494141 last_seq = 12490 current_ts = 504.511078 current_received_ts = 504.511078 current_seq = 12491 count = 107 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.511078 last_received_ts = 504.511078 last_seq = 12491 current_ts = 504.527771 current_received_ts = 504.527679 current_seq = 12492 count = 108 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.527771 last_received_ts = 504.527679 last_seq = 12492 current_ts = 504.544434 current_received_ts = 504.544189 current_seq = 12493 count = 109 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 22us (kms_flip:2509) DEBUG: name = flip last_ts = 504.544434 last_received_ts = 504.544189 last_seq = 12493 current_ts = 504.561066 current_received_ts = 504.561096 current_seq = 12494 count = 110 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.561066 last_received_ts = 504.561096 last_seq = 12494 current_ts = 504.577759 current_received_ts = 504.577698 current_seq = 12495 count = 111 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.577759 last_received_ts = 504.577698 last_seq = 12495 current_ts = 504.594421 current_received_ts = 504.594269 current_seq = 12496 count = 112 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.594421 last_received_ts = 504.594269 last_seq = 12496 current_ts = 504.611084 current_received_ts = 504.611084 current_seq = 12497 count = 113 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.611084 last_received_ts = 504.611084 last_seq = 12497 current_ts = 504.627747 current_received_ts = 504.627625 current_seq = 12498 count = 114 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 504.627747 last_received_ts = 504.627625 last_seq = 12498 current_ts = 504.644409 current_received_ts = 504.644196 current_seq = 12499 count = 115 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.644409 last_received_ts = 504.644196 last_seq = 12499 current_ts = 504.661072 current_received_ts = 504.660950 current_seq = 12500 count = 116 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 504.661072 last_received_ts = 504.660950 last_seq = 12500 current_ts = 504.677765 current_received_ts = 504.677643 current_seq = 12501 count = 117 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.677765 last_received_ts = 504.677643 last_seq = 12501 current_ts = 504.694427 current_received_ts = 504.694183 current_seq = 12502 count = 118 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.694427 last_received_ts = 504.694183 last_seq = 12502 current_ts = 504.711090 current_received_ts = 504.710876 current_seq = 12503 count = 119 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 21us (kms_flip:2509) DEBUG: name = flip last_ts = 504.711090 last_received_ts = 504.710876 last_seq = 12503 current_ts = 504.727753 current_received_ts = 504.727631 current_seq = 12504 count = 120 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.727753 last_received_ts = 504.727631 last_seq = 12504 current_ts = 504.744415 current_received_ts = 504.744354 current_seq = 12505 count = 121 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.744415 last_received_ts = 504.744354 last_seq = 12505 current_ts = 504.761078 current_received_ts = 504.760986 current_seq = 12506 count = 122 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.761078 last_received_ts = 504.760986 last_seq = 12506 current_ts = 504.777740 current_received_ts = 504.777618 current_seq = 12507 count = 123 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.777740 last_received_ts = 504.777618 last_seq = 12507 current_ts = 504.794403 current_received_ts = 504.794250 current_seq = 12508 count = 124 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.794403 last_received_ts = 504.794250 last_seq = 12508 current_ts = 504.811096 current_received_ts = 504.811066 current_seq = 12509 count = 125 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 27us (kms_flip:2509) DEBUG: name = flip last_ts = 504.811096 last_received_ts = 504.811066 last_seq = 12509 current_ts = 504.827759 current_received_ts = 504.827545 current_seq = 12510 count = 126 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 504.827759 last_received_ts = 504.827545 last_seq = 12510 current_ts = 504.844421 current_received_ts = 504.844330 current_seq = 12511 count = 127 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.844421 last_received_ts = 504.844330 last_seq = 12511 current_ts = 504.861084 current_received_ts = 504.860931 current_seq = 12512 count = 128 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 90us (kms_flip:2509) DEBUG: name = flip last_ts = 504.861084 last_received_ts = 504.860931 last_seq = 12512 current_ts = 504.877747 current_received_ts = 504.877594 current_seq = 12513 count = 129 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.877747 last_received_ts = 504.877594 last_seq = 12513 current_ts = 504.894409 current_received_ts = 504.894196 current_seq = 12514 count = 130 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.894409 last_received_ts = 504.894196 last_seq = 12514 current_ts = 504.911072 current_received_ts = 504.910950 current_seq = 12515 count = 131 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 68us (kms_flip:2509) DEBUG: name = flip last_ts = 504.911072 last_received_ts = 504.910950 last_seq = 12515 current_ts = 504.927765 current_received_ts = 504.927612 current_seq = 12516 count = 132 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.927765 last_received_ts = 504.927612 last_seq = 12516 current_ts = 504.944427 current_received_ts = 504.944244 current_seq = 12517 count = 133 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 504.944427 last_received_ts = 504.944244 last_seq = 12517 current_ts = 504.961090 current_received_ts = 504.960938 current_seq = 12518 count = 134 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 57us (kms_flip:2509) DEBUG: name = flip last_ts = 504.961090 last_received_ts = 504.960938 last_seq = 12518 current_ts = 504.977753 current_received_ts = 504.977661 current_seq = 12519 count = 135 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 504.977753 last_received_ts = 504.977661 last_seq = 12519 current_ts = 504.994415 current_received_ts = 504.994171 current_seq = 12520 count = 136 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 504.994415 last_received_ts = 504.994171 last_seq = 12520 current_ts = 505.011078 current_received_ts = 505.010956 current_seq = 12521 count = 137 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 63us (kms_flip:2509) DEBUG: name = flip last_ts = 505.011078 last_received_ts = 505.010956 last_seq = 12521 current_ts = 505.027740 current_received_ts = 505.027679 current_seq = 12522 count = 138 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 505.027740 last_received_ts = 505.027679 last_seq = 12522 current_ts = 505.044434 current_received_ts = 505.044250 current_seq = 12523 count = 139 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.044434 last_received_ts = 505.044250 last_seq = 12523 current_ts = 505.061096 current_received_ts = 505.060669 current_seq = 12524 count = 140 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 19us (kms_flip:2509) DEBUG: name = flip last_ts = 505.061096 last_received_ts = 505.060669 last_seq = 12524 current_ts = 505.077759 current_received_ts = 505.077606 current_seq = 12525 count = 141 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 22us (kms_flip:2509) DEBUG: name = flip last_ts = 505.077759 last_received_ts = 505.077606 last_seq = 12525 current_ts = 505.094421 current_received_ts = 505.094360 current_seq = 12526 count = 142 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.094421 last_received_ts = 505.094360 last_seq = 12526 current_ts = 505.111084 current_received_ts = 505.111084 current_seq = 12527 count = 143 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.111084 last_received_ts = 505.111084 last_seq = 12527 current_ts = 505.127747 current_received_ts = 505.127625 current_seq = 12528 count = 144 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 505.127747 last_received_ts = 505.127625 last_seq = 12528 current_ts = 505.144409 current_received_ts = 505.144257 current_seq = 12529 count = 145 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 505.144409 last_received_ts = 505.144257 last_seq = 12529 current_ts = 505.161102 current_received_ts = 505.161072 current_seq = 12530 count = 146 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.161102 last_received_ts = 505.161072 last_seq = 12530 current_ts = 505.177765 current_received_ts = 505.177673 current_seq = 12531 count = 147 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.177765 last_received_ts = 505.177673 last_seq = 12531 current_ts = 505.194427 current_received_ts = 505.194275 current_seq = 12532 count = 148 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 505.194427 last_received_ts = 505.194275 last_seq = 12532 current_ts = 505.211090 current_received_ts = 505.210938 current_seq = 12533 count = 149 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 76us (kms_flip:2509) DEBUG: name = flip last_ts = 505.211090 last_received_ts = 505.210938 last_seq = 12533 current_ts = 505.227753 current_received_ts = 505.227631 current_seq = 12534 count = 150 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 505.227753 last_received_ts = 505.227631 last_seq = 12534 current_ts = 505.244415 current_received_ts = 505.244354 current_seq = 12535 count = 151 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.244415 last_received_ts = 505.244354 last_seq = 12535 current_ts = 505.261108 current_received_ts = 505.261078 current_seq = 12536 count = 152 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 505.261108 last_received_ts = 505.261078 last_seq = 12536 current_ts = 505.277740 current_received_ts = 505.277679 current_seq = 12537 count = 153 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.277740 last_received_ts = 505.277679 last_seq = 12537 current_ts = 505.294403 current_received_ts = 505.294342 current_seq = 12538 count = 154 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 505.294403 last_received_ts = 505.294342 last_seq = 12538 current_ts = 505.311066 current_received_ts = 505.311066 current_seq = 12539 count = 155 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.311066 last_received_ts = 505.311066 last_seq = 12539 current_ts = 505.327759 current_received_ts = 505.327606 current_seq = 12540 count = 156 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 505.327759 last_received_ts = 505.327606 last_seq = 12540 current_ts = 505.344421 current_received_ts = 505.344238 current_seq = 12541 count = 157 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 505.344421 last_received_ts = 505.344238 last_seq = 12541 current_ts = 505.361084 current_received_ts = 505.360931 current_seq = 12542 count = 158 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 19us (kms_flip:2509) DEBUG: name = flip last_ts = 505.361084 last_received_ts = 505.360931 last_seq = 12542 current_ts = 505.377747 current_received_ts = 505.377563 current_seq = 12543 count = 159 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.377747 last_received_ts = 505.377563 last_seq = 12543 current_ts = 505.394440 current_received_ts = 505.394257 current_seq = 12544 count = 160 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.394440 last_received_ts = 505.394257 last_seq = 12544 current_ts = 505.411072 current_received_ts = 505.410919 current_seq = 12545 count = 161 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 96us (kms_flip:2509) DEBUG: name = flip last_ts = 505.411072 last_received_ts = 505.410919 last_seq = 12545 current_ts = 505.427734 current_received_ts = 505.427643 current_seq = 12546 count = 162 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.427734 last_received_ts = 505.427643 last_seq = 12546 current_ts = 505.444397 current_received_ts = 505.444244 current_seq = 12547 count = 163 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 23us (kms_flip:2509) DEBUG: name = flip last_ts = 505.444397 last_received_ts = 505.444244 last_seq = 12547 current_ts = 505.461090 current_received_ts = 505.460907 current_seq = 12548 count = 164 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 20us (kms_flip:2509) DEBUG: name = flip last_ts = 505.461090 last_received_ts = 505.460907 last_seq = 12548 current_ts = 505.477753 current_received_ts = 505.477661 current_seq = 12549 count = 165 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.477753 last_received_ts = 505.477661 last_seq = 12549 current_ts = 505.494415 current_received_ts = 505.494263 current_seq = 12550 count = 166 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.494415 last_received_ts = 505.494263 last_seq = 12550 current_ts = 505.511078 current_received_ts = 505.510986 current_seq = 12551 count = 167 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.511078 last_received_ts = 505.510986 last_seq = 12551 current_ts = 505.527771 current_received_ts = 505.527588 current_seq = 12552 count = 168 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 505.527771 last_received_ts = 505.527588 last_seq = 12552 current_ts = 505.544434 current_received_ts = 505.544281 current_seq = 12553 count = 169 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.544434 last_received_ts = 505.544281 last_seq = 12553 current_ts = 505.561066 current_received_ts = 505.560944 current_seq = 12554 count = 170 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 96us (kms_flip:2509) DEBUG: name = flip last_ts = 505.561066 last_received_ts = 505.560944 last_seq = 12554 current_ts = 505.577759 current_received_ts = 505.577545 current_seq = 12555 count = 171 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 24us (kms_flip:2509) DEBUG: name = flip last_ts = 505.577759 last_received_ts = 505.577545 last_seq = 12555 current_ts = 505.594421 current_received_ts = 505.594208 current_seq = 12556 count = 172 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 505.594421 last_received_ts = 505.594208 last_seq = 12556 current_ts = 505.611084 current_received_ts = 505.610931 current_seq = 12557 count = 173 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 66us (kms_flip:2509) DEBUG: name = flip last_ts = 505.611084 last_received_ts = 505.610931 last_seq = 12557 current_ts = 505.627747 current_received_ts = 505.627563 current_seq = 12558 count = 174 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 505.627747 last_received_ts = 505.627563 last_seq = 12558 current_ts = 505.644409 current_received_ts = 505.644135 current_seq = 12559 count = 175 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 25us (kms_flip:2509) DEBUG: name = flip last_ts = 505.644409 last_received_ts = 505.644135 last_seq = 12559 current_ts = 505.661072 current_received_ts = 505.660889 current_seq = 12560 count = 176 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 17us (kms_flip:2509) DEBUG: name = flip last_ts = 505.661072 last_received_ts = 505.660889 last_seq = 12560 current_ts = 505.677765 current_received_ts = 505.677582 current_seq = 12561 count = 177 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 22us (kms_flip:2509) DEBUG: name = flip last_ts = 505.677765 last_received_ts = 505.677582 last_seq = 12561 current_ts = 505.694427 current_received_ts = 505.694275 current_seq = 12562 count = 178 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 26us (kms_flip:2509) DEBUG: name = flip last_ts = 505.694427 last_received_ts = 505.694275 last_seq = 12562 current_ts = 505.711090 current_received_ts = 505.710938 current_seq = 12563 count = 179 seq_step = 1 (kms_flip:2509) DEBUG: Vblank took 566us (kms_flip:2509) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2509) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2509) igt_core-INFO: Stack trace: (kms_flip:2509) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2509) igt_core-INFO: #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() (kms_flip:2509) igt_core-INFO: #2 ../tests/kms_flip.c:1889 run_test() (kms_flip:2509) igt_core-INFO: #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045() (kms_flip:2509) igt_core-INFO: #4 ../tests/kms_flip.c:2045 main() (kms_flip:2509) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2509) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2509) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-HDMI-A2: FAIL (4.061s)
Dmesg	<6> [502.370875] [IGT] kms_flip: starting dynamic subtest B-HDMI-A2 <7> [502.372098] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:180] <7> [502.372462] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:181] <7> [502.426637] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:76:pipe A] <7> [502.427157] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [502.428180] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [502.428989] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [502.429846] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [502.430687] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000) <7> [502.431531] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [502.432373] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [502.433211] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [502.434016] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [502.434853] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [502.435688] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [502.436534] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [502.437366] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [502.438194] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [502.438618] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [502.438991] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0) <7> [502.439383] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0) <7> [502.439758] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [502.440143] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [502.440515] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [502.440886] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [502.441275] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [502.441647] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [502.442018] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [502.442406] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [502.442778] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [502.443167] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [502.443538] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0) <7> [502.443911] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0) <7> [502.444310] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [502.444682] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [502.445071] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [502.445446] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [502.445816] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [502.446203] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in has_hdmi_sink (expected yes, found no) <7> [502.446581] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in has_infoframe (expected yes, found no) <7> [502.446955] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [502.447346] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [502.447722] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [502.448111] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in port_clock (expected 148500, found 0) <7> [502.448482] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000) <7> [502.448856] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in avi infoframe <7> [502.449247] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [502.449620] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [502.449625] i915 0000:00:02.0: colorspace: RGB <7> [502.449628] i915 0000:00:02.0: scan mode: Underscan <7> [502.449632] i915 0000:00:02.0: colorimetry: No Data <7> [502.449635] i915 0000:00:02.0: picture aspect: No Data <7> [502.449639] i915 0000:00:02.0: active aspect: Same as Picture <7> [502.449642] i915 0000:00:02.0: itc: No Data <7> [502.449646] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [502.449649] i915 0000:00:02.0: quantization range: Full <7> [502.449652] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [502.449656] i915 0000:00:02.0: video code: 0 <7> [502.449659] i915 0000:00:02.0: ycc quantization range: Full <7> [502.449662] i915 0000:00:02.0: hdmi content type: Graphics <7> [502.449666] i915 0000:00:02.0: pixel repeat: 0 <7> [502.449669] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [502.449673] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [502.450058] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in spd infoframe <7> [502.450429] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [502.450800] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [502.450805] i915 0000:00:02.0: vendor: Intel <7> [502.450809] i915 0000:00:02.0: product: Integrated gfx <7> [502.450812] i915 0000:00:02.0: source device information: PC General (0x9) <7> [502.450816] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [502.451203] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hdmi infoframe <7> [502.451574] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [502.451942] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [502.451946] i915 0000:00:02.0: empty frame <7> [502.451950] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [502.452338] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:76:pipe A] fastset requirement not met, forcing full modeset <7> [502.452713] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:76:pipe A] releasing PORT PLL C <7> [502.453490] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:76:pipe A] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [502.454069] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:70:cursor A] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0 <7> [502.454522] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:76:pipe A] min cdclk: 192000 kHz -> 0 kHz <7> [502.454950] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [502.455341] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz <7> [502.455713] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4 <7> [502.456111] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:76:pipe A] enable: no [modeset] <7> [502.456491] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:plane 1A] fb: [NOFB], visible: no <7> [502.456863] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:43:plane 2A] fb: [NOFB], visible: no <7> [502.457256] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:52:plane 3A] fb: [NOFB], visible: no <7> [502.457627] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:61:plane 4A] fb: [NOFB], visible: no <7> [502.457997] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:70:cursor A] fb: [NOFB], visible: no <7> [502.458611] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:174:HDMI-A-2][ENCODER:173:DDI C/PHY C] Disable audio codec on [CRTC:76:pipe A] <7> [502.481086] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port C <7> [502.483253] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A <7> [502.493636] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10 <7> [502.498167] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time <7> [502.604610] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_C <7> [502.605952] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL C (active 0x1, on? 1) for [CRTC:76:pipe A] <7> [502.609777] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL C <7> [502.610385] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 79200 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 4 <7> [502.610822] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:163:DDI B/PHY B] <7> [502.611238] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:173:DDI C/PHY C] <7> [502.611657] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:174:HDMI-A-2] <7> [502.613034] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-c <7> [502.613761] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:76:pipe A] <7> [502.614965] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [502.615393] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz <7> [502.615765] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13 <7> [502.616258] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 316800 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 13 <7> [502.617022] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:119:pipe B] <7> [502.617449] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:162:pipe C] <7> [502.617755] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:119:pipe B] <7> [502.617814] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:174:HDMI-A-2] <7> [502.617961] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CONNECTOR:174:HDMI-A-2] Limiting display bpp to 30 (EDID bpp 36, max requested bpp 30, max platform bpp 36) <7> [502.618439] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24) <7> [502.618839] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:119:pipe B] hw max bpp: 30, pipe bpp: 24, dithering: 0 <7> [502.619264] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:173:DDI C/PHY C] [CRTC:119:pipe B] <7> [502.619638] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.enable (expected no, found yes) <7> [502.620014] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.active (expected no, found yes) <7> [502.620423] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1) <7> [502.620796] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in lane_count (expected 0, found 4) <7> [502.621202] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d) <7> [502.621575] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [502.621946] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [502.622358] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [502.622730] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [502.623135] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [502.623507] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [502.623878] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [502.624283] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [502.624655] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [502.625028] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [502.625421] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [502.625792] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [502.626179] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [502.626550] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [502.626920] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [502.627308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [502.627680] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [502.628066] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [502.628438] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [502.628808] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [502.629197] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [502.629569] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [502.629942] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [502.630335] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [502.630712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [502.631099] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [502.631470] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [502.631840] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [502.632229] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [502.632603] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [502.632976] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in has_infoframe (expected no, found yes) <7> [502.633365] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [502.633739] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [502.634127] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [502.634499] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in port_clock (expected 0, found 148500) <7> [502.634870] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [502.635257] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in avi infoframe <7> [502.635629] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [502.636001] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [502.636389] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [502.636395] i915 0000:00:02.0: colorspace: RGB <7> [502.636399] i915 0000:00:02.0: scan mode: Underscan <7> [502.636403] i915 0000:00:02.0: colorimetry: No Data <7> [502.636406] i915 0000:00:02.0: picture aspect: No Data <7> [502.636410] i915 0000:00:02.0: active aspect: Same as Picture <7> [502.636413] i915 0000:00:02.0: itc: No Data <7> [502.636416] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [502.636420] i915 0000:00:02.0: quantization range: Full <7> [502.636423] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [502.636426] i915 0000:00:02.0: video code: 0 <7> [502.636430] i915 0000:00:02.0: ycc quantization range: Full <7> [502.636433] i915 0000:00:02.0: hdmi content type: Graphics <7> [502.636436] i915 0000:00:02.0: pixel repeat: 0 <7> [502.636439] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [502.636443] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in spd infoframe <7> [502.636814] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [502.637200] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [502.637570] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [502.637575] i915 0000:00:02.0: vendor: Intel <7> [502.637578] i915 0000:00:02.0: product: Integrated gfx <7> [502.637582] i915 0000:00:02.0: source device information: PC General (0x9) <7> [502.637586] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hdmi infoframe <7> [502.637955] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [502.638342] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [502.638712] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [502.638716] i915 0000:00:02.0: empty frame <7> [502.638721] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:119:pipe B] fastset requirement not met, forcing full modeset <7> [502.639256] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:119:pipe B] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x2 <7> [502.639692] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:77:plane 1B] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988 <7> [502.640114] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:113:cursor B] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32 <7> [502.640483] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [502.640875] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0 <7> [502.641270] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0 <7> [502.641640] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0 <7> [502.643630] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL <7> [502.643647] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled <7> [502.645167] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:119:pipe B] min cdclk: 0 kHz -> 192000 kHz <7> [502.645689] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:119:pipe B] using pre-allocated PORT PLL C <7> [502.646099] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:119:pipe B] reserving PORT PLL C <7> [502.646480] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:119:pipe B] enable: yes [modeset] <7> [502.646865] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [502.647262] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 24, dithering: 0 <7> [502.647631] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [502.648001] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [502.648393] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [502.648761] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [502.649146] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [502.649516] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x0 <7> [502.649886] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [502.649891] i915 0000:00:02.0: colorspace: RGB <7> [502.649894] i915 0000:00:02.0: scan mode: Underscan <7> [502.649898] i915 0000:00:02.0: colorimetry: No Data <7> [502.649901] i915 0000:00:02.0: picture aspect: No Data <7> [502.649905] i915 0000:00:02.0: active aspect: Same as Picture <7> [502.649908] i915 0000:00:02.0: itc: No Data <7> [502.649912] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [502.649915] i915 0000:00:02.0: quantization range: Full <7> [502.649919] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [502.649922] i915 0000:00:02.0: video code: 0 <7> [502.649925] i915 0000:00:02.0: ycc quantization range: Full <7> [502.649928] i915 0000:00:02.0: hdmi content type: Graphics <7> [502.649932] i915 0000:00:02.0: pixel repeat: 0 <7> [502.649935] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [502.649939] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [502.649943] i915 0000:00:02.0: vendor: Intel <7> [502.649946] i915 0000:00:02.0: product: Integrated gfx <7> [502.649950] i915 0000:00:02.0: source device information: PC General (0x9) <7> [502.649954] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [502.649958] i915 0000:00:02.0: empty frame <7> [502.649962] 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> [502.650351] 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> [502.650720] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [502.651104] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [502.651476] 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> [502.651848] 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> [502.652255] 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> [502.652626] 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> [502.652996] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [502.653388] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [502.653764] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [502.654153] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000 <7> [502.654523] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0 <7> [502.654891] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [502.655278] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [502.655648] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [502.656016] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6300, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d <7> [502.656406] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [502.656775] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [502.657160] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [502.657529] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [502.657900] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [502.658285] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [502.658653] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [502.659023] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [502.659408] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:77:plane 1B] fb: [FB:180] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [502.659780] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [502.660162] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [502.660538] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:86:plane 2B] fb: [NOFB], visible: no <7> [502.660906] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3B] fb: [NOFB], visible: no <7> [502.661292] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:104:plane 4B] fb: [NOFB], visible: no <7> [502.661662] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:113:cursor B] fb: [NOFB], visible: no <7> [502.664221] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c <7> [502.665021] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:163:DDI B/PHY B] <7> [502.665452] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:173:DDI C/PHY C] <7> [502.666091] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x2, on? 0) for [CRTC:119:pipe B] <7> [502.666474] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C <7> [502.670605] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C <7> [502.671528] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe B <7> [502.689273] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:174:HDMI-A-2][ENCODER:173:DDI C/PHY C] Enable audio codec on [CRTC:119:pipe B], 32 bytes ELD <7> [502.705907] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000) <7> [502.706399] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N <7> [502.706962] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:174:HDMI-A-2] <7> [502.708981] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:119:pipe B] <6> [506.433318] [IGT] kms_flip: finished subtest B-HDMI-A2, FAIL

Detail

Value

Duration

4.06 seconds

Hostname

shard-glk6

Igt-Version

IGT-Version: 2.2-g3a460cb78 (x86_64) (Linux: 6.18.0-CI_DRM_17613-g4ee45005b554+ x86_64)

Out

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

Err

Starting dynamic subtest: B-HDMI-A2
(kms_flip:2509) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2509) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest B-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.677734
last_received_ts = 503.677612
last_seq = 12441
current_ts = 503.694427
current_received_ts = 503.694275
current_seq = 12442
count = 58
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.694427
last_received_ts = 503.694275
last_seq = 12442
current_ts = 503.711090
current_received_ts = 503.710907
current_seq = 12443
count = 59
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 21us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.711090
last_received_ts = 503.710907
last_seq = 12443
current_ts = 503.727753
current_received_ts = 503.727661
current_seq = 12444
count = 60
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.727753
last_received_ts = 503.727661
last_seq = 12444
current_ts = 503.744415
current_received_ts = 503.744293
current_seq = 12445
count = 61
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.744415
last_received_ts = 503.744293
last_seq = 12445
current_ts = 503.761078
current_received_ts = 503.760956
current_seq = 12446
count = 62
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 20us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.761078
last_received_ts = 503.760956
last_seq = 12446
current_ts = 503.777740
current_received_ts = 503.777679
current_seq = 12447
count = 63
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.777740
last_received_ts = 503.777679
last_seq = 12447
current_ts = 503.794434
current_received_ts = 503.794342
current_seq = 12448
count = 64
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.794434
last_received_ts = 503.794342
last_seq = 12448
current_ts = 503.811096
current_received_ts = 503.810974
current_seq = 12449
count = 65
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 27us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.811096
last_received_ts = 503.810974
last_seq = 12449
current_ts = 503.827759
current_received_ts = 503.827637
current_seq = 12450
count = 66
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.827759
last_received_ts = 503.827637
last_seq = 12450
current_ts = 503.844421
current_received_ts = 503.844330
current_seq = 12451
count = 67
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 27us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.844421
last_received_ts = 503.844330
last_seq = 12451
current_ts = 503.861084
current_received_ts = 503.860931
current_seq = 12452
count = 68
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 84us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.861084
last_received_ts = 503.860931
last_seq = 12452
current_ts = 503.877747
current_received_ts = 503.877686
current_seq = 12453
count = 69
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.877747
last_received_ts = 503.877686
last_seq = 12453
current_ts = 503.894409
current_received_ts = 503.894348
current_seq = 12454
count = 70
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.894409
last_received_ts = 503.894348
last_seq = 12454
current_ts = 503.911072
current_received_ts = 503.910950
current_seq = 12455
count = 71
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 17us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.911072
last_received_ts = 503.910950
last_seq = 12455
current_ts = 503.927765
current_received_ts = 503.927643
current_seq = 12456
count = 72
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.927765
last_received_ts = 503.927643
last_seq = 12456
current_ts = 503.944427
current_received_ts = 503.944336
current_seq = 12457
count = 73
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.944427
last_received_ts = 503.944336
last_seq = 12457
current_ts = 503.961090
current_received_ts = 503.960968
current_seq = 12458
count = 74
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.961090
last_received_ts = 503.960968
last_seq = 12458
current_ts = 503.977753
current_received_ts = 503.977631
current_seq = 12459
count = 75
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.977753
last_received_ts = 503.977631
last_seq = 12459
current_ts = 503.994415
current_received_ts = 503.994324
current_seq = 12460
count = 76
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 503.994415
last_received_ts = 503.994324
last_seq = 12460
current_ts = 504.011078
current_received_ts = 504.010895
current_seq = 12461
count = 77
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.011078
last_received_ts = 504.010895
last_seq = 12461
current_ts = 504.027740
current_received_ts = 504.027679
current_seq = 12462
count = 78
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.027740
last_received_ts = 504.027679
last_seq = 12462
current_ts = 504.044434
current_received_ts = 504.044342
current_seq = 12463
count = 79
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.044434
last_received_ts = 504.044342
last_seq = 12463
current_ts = 504.061096
current_received_ts = 504.060974
current_seq = 12464
count = 80
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 21us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.061096
last_received_ts = 504.060974
last_seq = 12464
current_ts = 504.077759
current_received_ts = 504.077667
current_seq = 12465
count = 81
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.077759
last_received_ts = 504.077667
last_seq = 12465
current_ts = 504.094421
current_received_ts = 504.094299
current_seq = 12466
count = 82
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.094421
last_received_ts = 504.094299
last_seq = 12466
current_ts = 504.111084
current_received_ts = 504.111084
current_seq = 12467
count = 83
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 27us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.111084
last_received_ts = 504.111084
last_seq = 12467
current_ts = 504.127747
current_received_ts = 504.127594
current_seq = 12468
count = 84
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.127747
last_received_ts = 504.127594
last_seq = 12468
current_ts = 504.144409
current_received_ts = 504.144287
current_seq = 12469
count = 85
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.144409
last_received_ts = 504.144287
last_seq = 12469
current_ts = 504.161102
current_received_ts = 504.160980
current_seq = 12470
count = 86
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.161102
last_received_ts = 504.160980
last_seq = 12470
current_ts = 504.177765
current_received_ts = 504.177643
current_seq = 12471
count = 87
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.177765
last_received_ts = 504.177643
last_seq = 12471
current_ts = 504.194427
current_received_ts = 504.194305
current_seq = 12472
count = 88
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.194427
last_received_ts = 504.194305
last_seq = 12472
current_ts = 504.211090
current_received_ts = 504.210938
current_seq = 12473
count = 89
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 90us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.211090
last_received_ts = 504.210938
last_seq = 12473
current_ts = 504.227753
current_received_ts = 504.227661
current_seq = 12474
count = 90
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.227753
last_received_ts = 504.227661
last_seq = 12474
current_ts = 504.244415
current_received_ts = 504.244171
current_seq = 12475
count = 91
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.244415
last_received_ts = 504.244171
last_seq = 12475
current_ts = 504.261078
current_received_ts = 504.260956
current_seq = 12476
count = 92
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.261078
last_received_ts = 504.260956
last_seq = 12476
current_ts = 504.277740
current_received_ts = 504.277618
current_seq = 12477
count = 93
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.277740
last_received_ts = 504.277618
last_seq = 12477
current_ts = 504.294403
current_received_ts = 504.294220
current_seq = 12478
count = 94
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 22us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.294403
last_received_ts = 504.294220
last_seq = 12478
current_ts = 504.311066
current_received_ts = 504.310913
current_seq = 12479
count = 95
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 98us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.311066
last_received_ts = 504.310913
last_seq = 12479
current_ts = 504.327759
current_received_ts = 504.327637
current_seq = 12480
count = 96
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.327759
last_received_ts = 504.327637
last_seq = 12480
current_ts = 504.344421
current_received_ts = 504.344055
current_seq = 12481
count = 97
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.344421
last_received_ts = 504.344055
last_seq = 12481
current_ts = 504.361084
current_received_ts = 504.360931
current_seq = 12482
count = 98
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.361084
last_received_ts = 504.360931
last_seq = 12482
current_ts = 504.377747
current_received_ts = 504.377594
current_seq = 12483
count = 99
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 22us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.377747
last_received_ts = 504.377594
last_seq = 12483
current_ts = 504.394409
current_received_ts = 504.393982
current_seq = 12484
count = 100
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.394409
last_received_ts = 504.393982
last_seq = 12484
current_ts = 504.411072
current_received_ts = 504.410919
current_seq = 12485
count = 101
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 109us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.411072
last_received_ts = 504.410919
last_seq = 12485
current_ts = 504.427765
current_received_ts = 504.427582
current_seq = 12486
count = 102
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.427765
last_received_ts = 504.427582
last_seq = 12486
current_ts = 504.444427
current_received_ts = 504.444275
current_seq = 12487
count = 103
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.444427
last_received_ts = 504.444275
last_seq = 12487
current_ts = 504.461090
current_received_ts = 504.460938
current_seq = 12488
count = 104
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 81us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.461090
last_received_ts = 504.460938
last_seq = 12488
current_ts = 504.477753
current_received_ts = 504.477631
current_seq = 12489
count = 105
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.477753
last_received_ts = 504.477631
last_seq = 12489
current_ts = 504.494415
current_received_ts = 504.494141
current_seq = 12490
count = 106
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.494415
last_received_ts = 504.494141
last_seq = 12490
current_ts = 504.511078
current_received_ts = 504.511078
current_seq = 12491
count = 107
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.511078
last_received_ts = 504.511078
last_seq = 12491
current_ts = 504.527771
current_received_ts = 504.527679
current_seq = 12492
count = 108
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.527771
last_received_ts = 504.527679
last_seq = 12492
current_ts = 504.544434
current_received_ts = 504.544189
current_seq = 12493
count = 109
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 22us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.544434
last_received_ts = 504.544189
last_seq = 12493
current_ts = 504.561066
current_received_ts = 504.561096
current_seq = 12494
count = 110
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.561066
last_received_ts = 504.561096
last_seq = 12494
current_ts = 504.577759
current_received_ts = 504.577698
current_seq = 12495
count = 111
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.577759
last_received_ts = 504.577698
last_seq = 12495
current_ts = 504.594421
current_received_ts = 504.594269
current_seq = 12496
count = 112
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.594421
last_received_ts = 504.594269
last_seq = 12496
current_ts = 504.611084
current_received_ts = 504.611084
current_seq = 12497
count = 113
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.611084
last_received_ts = 504.611084
last_seq = 12497
current_ts = 504.627747
current_received_ts = 504.627625
current_seq = 12498
count = 114
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.627747
last_received_ts = 504.627625
last_seq = 12498
current_ts = 504.644409
current_received_ts = 504.644196
current_seq = 12499
count = 115
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.644409
last_received_ts = 504.644196
last_seq = 12499
current_ts = 504.661072
current_received_ts = 504.660950
current_seq = 12500
count = 116
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.661072
last_received_ts = 504.660950
last_seq = 12500
current_ts = 504.677765
current_received_ts = 504.677643
current_seq = 12501
count = 117
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.677765
last_received_ts = 504.677643
last_seq = 12501
current_ts = 504.694427
current_received_ts = 504.694183
current_seq = 12502
count = 118
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.694427
last_received_ts = 504.694183
last_seq = 12502
current_ts = 504.711090
current_received_ts = 504.710876
current_seq = 12503
count = 119
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 21us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.711090
last_received_ts = 504.710876
last_seq = 12503
current_ts = 504.727753
current_received_ts = 504.727631
current_seq = 12504
count = 120
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.727753
last_received_ts = 504.727631
last_seq = 12504
current_ts = 504.744415
current_received_ts = 504.744354
current_seq = 12505
count = 121
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.744415
last_received_ts = 504.744354
last_seq = 12505
current_ts = 504.761078
current_received_ts = 504.760986
current_seq = 12506
count = 122
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.761078
last_received_ts = 504.760986
last_seq = 12506
current_ts = 504.777740
current_received_ts = 504.777618
current_seq = 12507
count = 123
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.777740
last_received_ts = 504.777618
last_seq = 12507
current_ts = 504.794403
current_received_ts = 504.794250
current_seq = 12508
count = 124
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.794403
last_received_ts = 504.794250
last_seq = 12508
current_ts = 504.811096
current_received_ts = 504.811066
current_seq = 12509
count = 125
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 27us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.811096
last_received_ts = 504.811066
last_seq = 12509
current_ts = 504.827759
current_received_ts = 504.827545
current_seq = 12510
count = 126
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.827759
last_received_ts = 504.827545
last_seq = 12510
current_ts = 504.844421
current_received_ts = 504.844330
current_seq = 12511
count = 127
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.844421
last_received_ts = 504.844330
last_seq = 12511
current_ts = 504.861084
current_received_ts = 504.860931
current_seq = 12512
count = 128
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 90us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.861084
last_received_ts = 504.860931
last_seq = 12512
current_ts = 504.877747
current_received_ts = 504.877594
current_seq = 12513
count = 129
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.877747
last_received_ts = 504.877594
last_seq = 12513
current_ts = 504.894409
current_received_ts = 504.894196
current_seq = 12514
count = 130
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.894409
last_received_ts = 504.894196
last_seq = 12514
current_ts = 504.911072
current_received_ts = 504.910950
current_seq = 12515
count = 131
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 68us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.911072
last_received_ts = 504.910950
last_seq = 12515
current_ts = 504.927765
current_received_ts = 504.927612
current_seq = 12516
count = 132
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.927765
last_received_ts = 504.927612
last_seq = 12516
current_ts = 504.944427
current_received_ts = 504.944244
current_seq = 12517
count = 133
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.944427
last_received_ts = 504.944244
last_seq = 12517
current_ts = 504.961090
current_received_ts = 504.960938
current_seq = 12518
count = 134
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 57us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.961090
last_received_ts = 504.960938
last_seq = 12518
current_ts = 504.977753
current_received_ts = 504.977661
current_seq = 12519
count = 135
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.977753
last_received_ts = 504.977661
last_seq = 12519
current_ts = 504.994415
current_received_ts = 504.994171
current_seq = 12520
count = 136
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 504.994415
last_received_ts = 504.994171
last_seq = 12520
current_ts = 505.011078
current_received_ts = 505.010956
current_seq = 12521
count = 137
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 63us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.011078
last_received_ts = 505.010956
last_seq = 12521
current_ts = 505.027740
current_received_ts = 505.027679
current_seq = 12522
count = 138
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.027740
last_received_ts = 505.027679
last_seq = 12522
current_ts = 505.044434
current_received_ts = 505.044250
current_seq = 12523
count = 139
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.044434
last_received_ts = 505.044250
last_seq = 12523
current_ts = 505.061096
current_received_ts = 505.060669
current_seq = 12524
count = 140
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 19us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.061096
last_received_ts = 505.060669
last_seq = 12524
current_ts = 505.077759
current_received_ts = 505.077606
current_seq = 12525
count = 141
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 22us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.077759
last_received_ts = 505.077606
last_seq = 12525
current_ts = 505.094421
current_received_ts = 505.094360
current_seq = 12526
count = 142
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.094421
last_received_ts = 505.094360
last_seq = 12526
current_ts = 505.111084
current_received_ts = 505.111084
current_seq = 12527
count = 143
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.111084
last_received_ts = 505.111084
last_seq = 12527
current_ts = 505.127747
current_received_ts = 505.127625
current_seq = 12528
count = 144
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.127747
last_received_ts = 505.127625
last_seq = 12528
current_ts = 505.144409
current_received_ts = 505.144257
current_seq = 12529
count = 145
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.144409
last_received_ts = 505.144257
last_seq = 12529
current_ts = 505.161102
current_received_ts = 505.161072
current_seq = 12530
count = 146
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.161102
last_received_ts = 505.161072
last_seq = 12530
current_ts = 505.177765
current_received_ts = 505.177673
current_seq = 12531
count = 147
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.177765
last_received_ts = 505.177673
last_seq = 12531
current_ts = 505.194427
current_received_ts = 505.194275
current_seq = 12532
count = 148
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.194427
last_received_ts = 505.194275
last_seq = 12532
current_ts = 505.211090
current_received_ts = 505.210938
current_seq = 12533
count = 149
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 76us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.211090
last_received_ts = 505.210938
last_seq = 12533
current_ts = 505.227753
current_received_ts = 505.227631
current_seq = 12534
count = 150
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.227753
last_received_ts = 505.227631
last_seq = 12534
current_ts = 505.244415
current_received_ts = 505.244354
current_seq = 12535
count = 151
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.244415
last_received_ts = 505.244354
last_seq = 12535
current_ts = 505.261108
current_received_ts = 505.261078
current_seq = 12536
count = 152
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.261108
last_received_ts = 505.261078
last_seq = 12536
current_ts = 505.277740
current_received_ts = 505.277679
current_seq = 12537
count = 153
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.277740
last_received_ts = 505.277679
last_seq = 12537
current_ts = 505.294403
current_received_ts = 505.294342
current_seq = 12538
count = 154
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.294403
last_received_ts = 505.294342
last_seq = 12538
current_ts = 505.311066
current_received_ts = 505.311066
current_seq = 12539
count = 155
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.311066
last_received_ts = 505.311066
last_seq = 12539
current_ts = 505.327759
current_received_ts = 505.327606
current_seq = 12540
count = 156
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.327759
last_received_ts = 505.327606
last_seq = 12540
current_ts = 505.344421
current_received_ts = 505.344238
current_seq = 12541
count = 157
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.344421
last_received_ts = 505.344238
last_seq = 12541
current_ts = 505.361084
current_received_ts = 505.360931
current_seq = 12542
count = 158
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 19us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.361084
last_received_ts = 505.360931
last_seq = 12542
current_ts = 505.377747
current_received_ts = 505.377563
current_seq = 12543
count = 159
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.377747
last_received_ts = 505.377563
last_seq = 12543
current_ts = 505.394440
current_received_ts = 505.394257
current_seq = 12544
count = 160
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.394440
last_received_ts = 505.394257
last_seq = 12544
current_ts = 505.411072
current_received_ts = 505.410919
current_seq = 12545
count = 161
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 96us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.411072
last_received_ts = 505.410919
last_seq = 12545
current_ts = 505.427734
current_received_ts = 505.427643
current_seq = 12546
count = 162
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.427734
last_received_ts = 505.427643
last_seq = 12546
current_ts = 505.444397
current_received_ts = 505.444244
current_seq = 12547
count = 163
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 23us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.444397
last_received_ts = 505.444244
last_seq = 12547
current_ts = 505.461090
current_received_ts = 505.460907
current_seq = 12548
count = 164
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 20us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.461090
last_received_ts = 505.460907
last_seq = 12548
current_ts = 505.477753
current_received_ts = 505.477661
current_seq = 12549
count = 165
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.477753
last_received_ts = 505.477661
last_seq = 12549
current_ts = 505.494415
current_received_ts = 505.494263
current_seq = 12550
count = 166
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.494415
last_received_ts = 505.494263
last_seq = 12550
current_ts = 505.511078
current_received_ts = 505.510986
current_seq = 12551
count = 167
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.511078
last_received_ts = 505.510986
last_seq = 12551
current_ts = 505.527771
current_received_ts = 505.527588
current_seq = 12552
count = 168
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.527771
last_received_ts = 505.527588
last_seq = 12552
current_ts = 505.544434
current_received_ts = 505.544281
current_seq = 12553
count = 169
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.544434
last_received_ts = 505.544281
last_seq = 12553
current_ts = 505.561066
current_received_ts = 505.560944
current_seq = 12554
count = 170
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 96us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.561066
last_received_ts = 505.560944
last_seq = 12554
current_ts = 505.577759
current_received_ts = 505.577545
current_seq = 12555
count = 171
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 24us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.577759
last_received_ts = 505.577545
last_seq = 12555
current_ts = 505.594421
current_received_ts = 505.594208
current_seq = 12556
count = 172
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.594421
last_received_ts = 505.594208
last_seq = 12556
current_ts = 505.611084
current_received_ts = 505.610931
current_seq = 12557
count = 173
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 66us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.611084
last_received_ts = 505.610931
last_seq = 12557
current_ts = 505.627747
current_received_ts = 505.627563
current_seq = 12558
count = 174
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.627747
last_received_ts = 505.627563
last_seq = 12558
current_ts = 505.644409
current_received_ts = 505.644135
current_seq = 12559
count = 175
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 25us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.644409
last_received_ts = 505.644135
last_seq = 12559
current_ts = 505.661072
current_received_ts = 505.660889
current_seq = 12560
count = 176
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 17us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.661072
last_received_ts = 505.660889
last_seq = 12560
current_ts = 505.677765
current_received_ts = 505.677582
current_seq = 12561
count = 177
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 22us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.677765
last_received_ts = 505.677582
last_seq = 12561
current_ts = 505.694427
current_received_ts = 505.694275
current_seq = 12562
count = 178
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 26us
(kms_flip:2509) DEBUG: name = flip
last_ts = 505.694427
last_received_ts = 505.694275
last_seq = 12562
current_ts = 505.711090
current_received_ts = 505.710938
current_seq = 12563
count = 179
seq_step = 1
(kms_flip:2509) DEBUG: Vblank took 566us
(kms_flip:2509) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2509) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2509) igt_core-INFO: Stack trace:
(kms_flip:2509) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2509) igt_core-INFO:   #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
(kms_flip:2509) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:2509) igt_core-INFO:   #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
(kms_flip:2509) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:2509) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2509) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2509) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-HDMI-A2: FAIL (4.061s)

Dmesg

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

<7> [502.372098] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:180]

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

<7> [502.426637] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:76:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [502.613761] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:76:pipe A]

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

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

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

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

<7> [502.617022] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:119:pipe B]

<7> [502.617449] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:162:pipe C]

<7> [502.617755] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:119:pipe B]

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

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

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

<7> [502.618839] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:119:pipe B] hw max bpp: 30, pipe bpp: 24, dithering: 0

<7> [502.619264] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:173:DDI C/PHY C] [CRTC:119:pipe B]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [502.641640] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0

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

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

<7> [502.645167] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:119:pipe B] min cdclk: 0 kHz -> 192000 kHz

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [502.649962] 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> [502.650351] 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> [502.650720] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2

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

<7> [502.651476] 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> [502.651848] 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> [502.652255] 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> [502.652626] 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> [502.652996] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [502.708981] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:119:pipe B]

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

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