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

Detail	Value
Duration	3.90 seconds
Hostname	shard-snb6
Igt-Version	IGT-Version: 2.4-g3ef61dd87 (x86_64) (Linux: 7.1.0-rc2-CI_DRM_18408-ge798c5cca30e+ x86_64)
Out	Starting dynamic subtest: A-HDMI-A1 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A1: FAIL (3.902s)
Err	Starting dynamic subtest: A-HDMI-A1 (kms_flip:2775) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2775) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-HDMI-A1 failed. ** DEBUG (kms_flip:2775) DEBUG: name = flip last_ts = 439.896240 last_received_ts = 439.895813 last_seq = 10134 current_ts = 439.912872 current_received_ts = 439.912415 current_seq = 10135 count = 79 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 7us (kms_flip:2775) DEBUG: name = flip last_ts = 439.912872 last_received_ts = 439.912415 last_seq = 10135 current_ts = 439.929504 current_received_ts = 439.929077 current_seq = 10136 count = 80 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 7us (kms_flip:2775) DEBUG: name = flip last_ts = 439.929504 last_received_ts = 439.929077 last_seq = 10136 current_ts = 439.946136 current_received_ts = 439.945679 current_seq = 10137 count = 81 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 439.946136 last_received_ts = 439.945679 last_seq = 10137 current_ts = 439.962769 current_received_ts = 439.962311 current_seq = 10138 count = 82 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 439.962769 last_received_ts = 439.962311 last_seq = 10138 current_ts = 439.979401 current_received_ts = 439.978943 current_seq = 10139 count = 83 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 439.979401 last_received_ts = 439.978943 last_seq = 10139 current_ts = 439.996033 current_received_ts = 439.995605 current_seq = 10140 count = 84 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 439.996033 last_received_ts = 439.995605 last_seq = 10140 current_ts = 440.012665 current_received_ts = 440.012238 current_seq = 10141 count = 85 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.012665 last_received_ts = 440.012238 last_seq = 10141 current_ts = 440.029297 current_received_ts = 440.028778 current_seq = 10142 count = 86 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.029297 last_received_ts = 440.028778 last_seq = 10142 current_ts = 440.045929 current_received_ts = 440.045471 current_seq = 10143 count = 87 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.045929 last_received_ts = 440.045471 last_seq = 10143 current_ts = 440.062561 current_received_ts = 440.062103 current_seq = 10144 count = 88 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 440.062561 last_received_ts = 440.062103 last_seq = 10144 current_ts = 440.079193 current_received_ts = 440.078766 current_seq = 10145 count = 89 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.079193 last_received_ts = 440.078766 last_seq = 10145 current_ts = 440.095825 current_received_ts = 440.095398 current_seq = 10146 count = 90 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.095825 last_received_ts = 440.095398 last_seq = 10146 current_ts = 440.112457 current_received_ts = 440.112061 current_seq = 10147 count = 91 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.112457 last_received_ts = 440.112061 last_seq = 10147 current_ts = 440.129089 current_received_ts = 440.128662 current_seq = 10148 count = 92 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.129089 last_received_ts = 440.128662 last_seq = 10148 current_ts = 440.145721 current_received_ts = 440.145294 current_seq = 10149 count = 93 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.145721 last_received_ts = 440.145294 last_seq = 10149 current_ts = 440.162354 current_received_ts = 440.161926 current_seq = 10150 count = 94 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.162354 last_received_ts = 440.161926 last_seq = 10150 current_ts = 440.178986 current_received_ts = 440.178528 current_seq = 10151 count = 95 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 440.178986 last_received_ts = 440.178528 last_seq = 10151 current_ts = 440.195618 current_received_ts = 440.195160 current_seq = 10152 count = 96 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.195618 last_received_ts = 440.195160 last_seq = 10152 current_ts = 440.212250 current_received_ts = 440.211792 current_seq = 10153 count = 97 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 440.212250 last_received_ts = 440.211792 last_seq = 10153 current_ts = 440.228882 current_received_ts = 440.228424 current_seq = 10154 count = 98 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.228882 last_received_ts = 440.228424 last_seq = 10154 current_ts = 440.245514 current_received_ts = 440.245117 current_seq = 10155 count = 99 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.245514 last_received_ts = 440.245117 last_seq = 10155 current_ts = 440.262146 current_received_ts = 440.261719 current_seq = 10156 count = 100 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.262146 last_received_ts = 440.261719 last_seq = 10156 current_ts = 440.278778 current_received_ts = 440.278351 current_seq = 10157 count = 101 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.278778 last_received_ts = 440.278351 last_seq = 10157 current_ts = 440.295410 current_received_ts = 440.294983 current_seq = 10158 count = 102 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.295410 last_received_ts = 440.294983 last_seq = 10158 current_ts = 440.312042 current_received_ts = 440.311615 current_seq = 10159 count = 103 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.312042 last_received_ts = 440.311615 last_seq = 10159 current_ts = 440.328674 current_received_ts = 440.328247 current_seq = 10160 count = 104 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.328674 last_received_ts = 440.328247 last_seq = 10160 current_ts = 440.345306 current_received_ts = 440.344879 current_seq = 10161 count = 105 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.345306 last_received_ts = 440.344879 last_seq = 10161 current_ts = 440.361938 current_received_ts = 440.361511 current_seq = 10162 count = 106 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.361938 last_received_ts = 440.361511 last_seq = 10162 current_ts = 440.378601 current_received_ts = 440.378143 current_seq = 10163 count = 107 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.378601 last_received_ts = 440.378143 last_seq = 10163 current_ts = 440.395233 current_received_ts = 440.394775 current_seq = 10164 count = 108 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 440.395233 last_received_ts = 440.394775 last_seq = 10164 current_ts = 440.411865 current_received_ts = 440.411407 current_seq = 10165 count = 109 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.411865 last_received_ts = 440.411407 last_seq = 10165 current_ts = 440.428497 current_received_ts = 440.428070 current_seq = 10166 count = 110 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 7us (kms_flip:2775) DEBUG: name = flip last_ts = 440.428497 last_received_ts = 440.428070 last_seq = 10166 current_ts = 440.445129 current_received_ts = 440.444672 current_seq = 10167 count = 111 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.445129 last_received_ts = 440.444672 last_seq = 10167 current_ts = 440.461761 current_received_ts = 440.461304 current_seq = 10168 count = 112 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.461761 last_received_ts = 440.461304 last_seq = 10168 current_ts = 440.478394 current_received_ts = 440.477936 current_seq = 10169 count = 113 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.478394 last_received_ts = 440.477936 last_seq = 10169 current_ts = 440.495026 current_received_ts = 440.494568 current_seq = 10170 count = 114 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.495026 last_received_ts = 440.494568 last_seq = 10170 current_ts = 440.511658 current_received_ts = 440.511200 current_seq = 10171 count = 115 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.511658 last_received_ts = 440.511200 last_seq = 10171 current_ts = 440.528290 current_received_ts = 440.527802 current_seq = 10172 count = 116 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.528290 last_received_ts = 440.527802 last_seq = 10172 current_ts = 440.544922 current_received_ts = 440.544464 current_seq = 10173 count = 117 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.544922 last_received_ts = 440.544464 last_seq = 10173 current_ts = 440.561554 current_received_ts = 440.561096 current_seq = 10174 count = 118 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 440.561554 last_received_ts = 440.561096 last_seq = 10174 current_ts = 440.578186 current_received_ts = 440.577698 current_seq = 10175 count = 119 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.578186 last_received_ts = 440.577698 last_seq = 10175 current_ts = 440.594818 current_received_ts = 440.594391 current_seq = 10176 count = 120 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.594818 last_received_ts = 440.594391 last_seq = 10176 current_ts = 440.611450 current_received_ts = 440.611053 current_seq = 10177 count = 121 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 440.611450 last_received_ts = 440.611053 last_seq = 10177 current_ts = 440.628082 current_received_ts = 440.627625 current_seq = 10178 count = 122 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.628082 last_received_ts = 440.627625 last_seq = 10178 current_ts = 440.644714 current_received_ts = 440.644257 current_seq = 10179 count = 123 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.644714 last_received_ts = 440.644257 last_seq = 10179 current_ts = 440.661346 current_received_ts = 440.660889 current_seq = 10180 count = 124 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.661346 last_received_ts = 440.660889 last_seq = 10180 current_ts = 440.677979 current_received_ts = 440.677551 current_seq = 10181 count = 125 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.677979 last_received_ts = 440.677551 last_seq = 10181 current_ts = 440.694611 current_received_ts = 440.694061 current_seq = 10182 count = 126 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.694611 last_received_ts = 440.694061 last_seq = 10182 current_ts = 440.711243 current_received_ts = 440.710663 current_seq = 10183 count = 127 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 5us (kms_flip:2775) DEBUG: name = flip last_ts = 440.711243 last_received_ts = 440.710663 last_seq = 10183 current_ts = 440.727875 current_received_ts = 440.727325 current_seq = 10184 count = 128 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 5us (kms_flip:2775) DEBUG: name = flip last_ts = 440.727875 last_received_ts = 440.727325 last_seq = 10184 current_ts = 440.744507 current_received_ts = 440.743896 current_seq = 10185 count = 129 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 5us (kms_flip:2775) DEBUG: name = flip last_ts = 440.744507 last_received_ts = 440.743896 last_seq = 10185 current_ts = 440.761139 current_received_ts = 440.760590 current_seq = 10186 count = 130 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 5us (kms_flip:2775) DEBUG: name = flip last_ts = 440.761139 last_received_ts = 440.760590 last_seq = 10186 current_ts = 440.777771 current_received_ts = 440.777283 current_seq = 10187 count = 131 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.777771 last_received_ts = 440.777283 last_seq = 10187 current_ts = 440.794403 current_received_ts = 440.793976 current_seq = 10188 count = 132 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 36us (kms_flip:2775) DEBUG: name = flip last_ts = 440.794403 last_received_ts = 440.793976 last_seq = 10188 current_ts = 440.811035 current_received_ts = 440.810608 current_seq = 10189 count = 133 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.811035 last_received_ts = 440.810608 last_seq = 10189 current_ts = 440.827667 current_received_ts = 440.827209 current_seq = 10190 count = 134 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.827667 last_received_ts = 440.827209 last_seq = 10190 current_ts = 440.844299 current_received_ts = 440.843872 current_seq = 10191 count = 135 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 6us (kms_flip:2775) DEBUG: name = flip last_ts = 440.844299 last_received_ts = 440.843872 last_seq = 10191 current_ts = 440.860931 current_received_ts = 440.860504 current_seq = 10192 count = 136 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.860931 last_received_ts = 440.860504 last_seq = 10192 current_ts = 440.877563 current_received_ts = 440.877106 current_seq = 10193 count = 137 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.877563 last_received_ts = 440.877106 last_seq = 10193 current_ts = 440.894196 current_received_ts = 440.893768 current_seq = 10194 count = 138 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.894196 last_received_ts = 440.893768 last_seq = 10194 current_ts = 440.910828 current_received_ts = 440.910400 current_seq = 10195 count = 139 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.910828 last_received_ts = 440.910400 last_seq = 10195 current_ts = 440.927460 current_received_ts = 440.927124 current_seq = 10196 count = 140 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.927460 last_received_ts = 440.927124 last_seq = 10196 current_ts = 440.944092 current_received_ts = 440.943695 current_seq = 10197 count = 141 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.944092 last_received_ts = 440.943695 last_seq = 10197 current_ts = 440.960724 current_received_ts = 440.960327 current_seq = 10198 count = 142 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 7us (kms_flip:2775) DEBUG: name = flip last_ts = 440.960724 last_received_ts = 440.960327 last_seq = 10198 current_ts = 440.977356 current_received_ts = 440.976929 current_seq = 10199 count = 143 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 440.977356 last_received_ts = 440.976929 last_seq = 10199 current_ts = 440.994019 current_received_ts = 440.993591 current_seq = 10200 count = 144 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 7us (kms_flip:2775) DEBUG: name = flip last_ts = 440.994019 last_received_ts = 440.993591 last_seq = 10200 current_ts = 441.010651 current_received_ts = 441.010193 current_seq = 10201 count = 145 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.010651 last_received_ts = 441.010193 last_seq = 10201 current_ts = 441.027283 current_received_ts = 441.026794 current_seq = 10202 count = 146 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.027283 last_received_ts = 441.026794 last_seq = 10202 current_ts = 441.043915 current_received_ts = 441.043457 current_seq = 10203 count = 147 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.043915 last_received_ts = 441.043457 last_seq = 10203 current_ts = 441.060547 current_received_ts = 441.060120 current_seq = 10204 count = 148 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.060547 last_received_ts = 441.060120 last_seq = 10204 current_ts = 441.077179 current_received_ts = 441.076752 current_seq = 10205 count = 149 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.077179 last_received_ts = 441.076752 last_seq = 10205 current_ts = 441.093811 current_received_ts = 441.093384 current_seq = 10206 count = 150 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.093811 last_received_ts = 441.093384 last_seq = 10206 current_ts = 441.110443 current_received_ts = 441.109985 current_seq = 10207 count = 151 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.110443 last_received_ts = 441.109985 last_seq = 10207 current_ts = 441.127075 current_received_ts = 441.126617 current_seq = 10208 count = 152 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 441.127075 last_received_ts = 441.126617 last_seq = 10208 current_ts = 441.143707 current_received_ts = 441.143250 current_seq = 10209 count = 153 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.143707 last_received_ts = 441.143250 last_seq = 10209 current_ts = 441.160339 current_received_ts = 441.159882 current_seq = 10210 count = 154 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 441.160339 last_received_ts = 441.159882 last_seq = 10210 current_ts = 441.176971 current_received_ts = 441.176514 current_seq = 10211 count = 155 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.176971 last_received_ts = 441.176514 last_seq = 10211 current_ts = 441.193604 current_received_ts = 441.193146 current_seq = 10212 count = 156 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.193604 last_received_ts = 441.193146 last_seq = 10212 current_ts = 441.210236 current_received_ts = 441.209778 current_seq = 10213 count = 157 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.210236 last_received_ts = 441.209778 last_seq = 10213 current_ts = 441.226868 current_received_ts = 441.226410 current_seq = 10214 count = 158 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 441.226868 last_received_ts = 441.226410 last_seq = 10214 current_ts = 441.243500 current_received_ts = 441.243103 current_seq = 10215 count = 159 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.243500 last_received_ts = 441.243103 last_seq = 10215 current_ts = 441.260132 current_received_ts = 441.259674 current_seq = 10216 count = 160 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.260132 last_received_ts = 441.259674 last_seq = 10216 current_ts = 441.276764 current_received_ts = 441.276306 current_seq = 10217 count = 161 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 441.276764 last_received_ts = 441.276306 last_seq = 10217 current_ts = 441.293396 current_received_ts = 441.292969 current_seq = 10218 count = 162 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.293396 last_received_ts = 441.292969 last_seq = 10218 current_ts = 441.310028 current_received_ts = 441.309601 current_seq = 10219 count = 163 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.310028 last_received_ts = 441.309601 last_seq = 10219 current_ts = 441.326660 current_received_ts = 441.326233 current_seq = 10220 count = 164 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.326660 last_received_ts = 441.326233 last_seq = 10220 current_ts = 441.343292 current_received_ts = 441.342834 current_seq = 10221 count = 165 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.343292 last_received_ts = 441.342834 last_seq = 10221 current_ts = 441.359924 current_received_ts = 441.359497 current_seq = 10222 count = 166 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.359924 last_received_ts = 441.359497 last_seq = 10222 current_ts = 441.376556 current_received_ts = 441.376099 current_seq = 10223 count = 167 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.376556 last_received_ts = 441.376099 last_seq = 10223 current_ts = 441.393188 current_received_ts = 441.392761 current_seq = 10224 count = 168 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.393188 last_received_ts = 441.392761 last_seq = 10224 current_ts = 441.409821 current_received_ts = 441.409393 current_seq = 10225 count = 169 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.409821 last_received_ts = 441.409393 last_seq = 10225 current_ts = 441.426453 current_received_ts = 441.426025 current_seq = 10226 count = 170 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 441.426453 last_received_ts = 441.426025 last_seq = 10226 current_ts = 441.443085 current_received_ts = 441.442657 current_seq = 10227 count = 171 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 6us (kms_flip:2775) DEBUG: name = flip last_ts = 441.443085 last_received_ts = 441.442657 last_seq = 10227 current_ts = 441.459717 current_received_ts = 441.459290 current_seq = 10228 count = 172 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.459717 last_received_ts = 441.459290 last_seq = 10228 current_ts = 441.476349 current_received_ts = 441.475922 current_seq = 10229 count = 173 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.476349 last_received_ts = 441.475922 last_seq = 10229 current_ts = 441.492981 current_received_ts = 441.492554 current_seq = 10230 count = 174 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.492981 last_received_ts = 441.492554 last_seq = 10230 current_ts = 441.509613 current_received_ts = 441.509186 current_seq = 10231 count = 175 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.509613 last_received_ts = 441.509186 last_seq = 10231 current_ts = 441.526245 current_received_ts = 441.525787 current_seq = 10232 count = 176 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.526245 last_received_ts = 441.525787 last_seq = 10232 current_ts = 441.542877 current_received_ts = 441.542450 current_seq = 10233 count = 177 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.542877 last_received_ts = 441.542450 last_seq = 10233 current_ts = 441.559540 current_received_ts = 441.559052 current_seq = 10234 count = 178 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.559540 last_received_ts = 441.559052 last_seq = 10234 current_ts = 441.576172 current_received_ts = 441.575623 current_seq = 10235 count = 179 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.576172 last_received_ts = 441.575623 last_seq = 10235 current_ts = 441.592804 current_received_ts = 441.592346 current_seq = 10236 count = 180 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.592804 last_received_ts = 441.592346 last_seq = 10236 current_ts = 441.609436 current_received_ts = 441.608978 current_seq = 10237 count = 181 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.609436 last_received_ts = 441.608978 last_seq = 10237 current_ts = 441.626068 current_received_ts = 441.625641 current_seq = 10238 count = 182 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 7us (kms_flip:2775) DEBUG: name = flip last_ts = 441.626068 last_received_ts = 441.625641 last_seq = 10238 current_ts = 441.642700 current_received_ts = 441.642242 current_seq = 10239 count = 183 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.642700 last_received_ts = 441.642242 last_seq = 10239 current_ts = 441.659332 current_received_ts = 441.658875 current_seq = 10240 count = 184 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 7us (kms_flip:2775) DEBUG: name = flip last_ts = 441.659332 last_received_ts = 441.658875 last_seq = 10240 current_ts = 441.675964 current_received_ts = 441.675507 current_seq = 10241 count = 185 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.675964 last_received_ts = 441.675507 last_seq = 10241 current_ts = 441.692596 current_received_ts = 441.692139 current_seq = 10242 count = 186 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.692596 last_received_ts = 441.692139 last_seq = 10242 current_ts = 441.709229 current_received_ts = 441.708801 current_seq = 10243 count = 187 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.709229 last_received_ts = 441.708801 last_seq = 10243 current_ts = 441.725861 current_received_ts = 441.725403 current_seq = 10244 count = 188 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 9us (kms_flip:2775) DEBUG: name = flip last_ts = 441.725861 last_received_ts = 441.725403 last_seq = 10244 current_ts = 441.742493 current_received_ts = 441.742065 current_seq = 10245 count = 189 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.742493 last_received_ts = 441.742065 last_seq = 10245 current_ts = 441.759125 current_received_ts = 441.758698 current_seq = 10246 count = 190 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.759125 last_received_ts = 441.758698 last_seq = 10246 current_ts = 441.775757 current_received_ts = 441.775299 current_seq = 10247 count = 191 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.775757 last_received_ts = 441.775299 last_seq = 10247 current_ts = 441.792389 current_received_ts = 441.791962 current_seq = 10248 count = 192 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.792389 last_received_ts = 441.791962 last_seq = 10248 current_ts = 441.809021 current_received_ts = 441.808563 current_seq = 10249 count = 193 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.809021 last_received_ts = 441.808563 last_seq = 10249 current_ts = 441.825653 current_received_ts = 441.825195 current_seq = 10250 count = 194 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.825653 last_received_ts = 441.825195 last_seq = 10250 current_ts = 441.842285 current_received_ts = 441.841858 current_seq = 10251 count = 195 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 6us (kms_flip:2775) DEBUG: name = flip last_ts = 441.842285 last_received_ts = 441.841858 last_seq = 10251 current_ts = 441.858917 current_received_ts = 441.858490 current_seq = 10252 count = 196 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.858917 last_received_ts = 441.858490 last_seq = 10252 current_ts = 441.875549 current_received_ts = 441.875122 current_seq = 10253 count = 197 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.875549 last_received_ts = 441.875122 last_seq = 10253 current_ts = 441.892181 current_received_ts = 441.891754 current_seq = 10254 count = 198 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.892181 last_received_ts = 441.891754 last_seq = 10254 current_ts = 441.908813 current_received_ts = 441.908386 current_seq = 10255 count = 199 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 8us (kms_flip:2775) DEBUG: name = flip last_ts = 441.908813 last_received_ts = 441.908386 last_seq = 10255 current_ts = 441.925446 current_received_ts = 441.924988 current_seq = 10256 count = 200 seq_step = 1 (kms_flip:2775) DEBUG: Vblank took 514us (kms_flip:2775) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2775) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2775) igt_core-INFO: Stack trace: (kms_flip:2775) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2775) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:2775) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:2775) igt_core-INFO: #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105() (kms_flip:2775) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:2775) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2775) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2775) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A1: FAIL (3.902s)
Dmesg	<6> [438.667682] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1 <7> [438.668248] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:90] <7> [438.668384] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:91] <7> [438.722038] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A] <7> [438.722373] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:72:pipe B] <7> [438.722546] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.enable (expected yes, found no) <7> [438.723117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.active (expected yes, found no) <7> [438.723700] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1) <7> [438.724210] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in has_pch_encoder (expected yes, found no) <7> [438.724712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in fdi_lanes (expected 1, found 0) <7> [438.725237] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0) <7> [438.725555] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in output_types (expected 0x00000002, found 0x00000000) <7> [438.725826] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [438.726151] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1024, found 0) <7> [438.726387] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 1344, found 0) <7> [438.726616] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1024, found 0) <7> [438.726883] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 1344, found 0) <7> [438.727130] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 1048, found 0) <7> [438.727365] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 1184, found 0) <7> [438.727612] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 768, found 0) <7> [438.727913] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 768, found 0) <7> [438.728200] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 771, found 0) <7> [438.728432] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 777, found 0) <7> [438.728663] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 806, found 0) <7> [438.728937] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 806, found 0) <7> [438.729210] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1024, found 0) <7> [438.729456] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 1344, found 0) <7> [438.729799] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1024, found 0) <7> [438.730066] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 1344, found 0) <7> [438.730297] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 1048, found 0) <7> [438.730527] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 1184, found 0) <7> [438.730789] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 768, found 0) <7> [438.731078] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 768, found 0) <7> [438.731308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 771, found 0) <7> [438.731537] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 777, found 0) <7> [438.731811] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 806, found 0) <7> [438.732113] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 806, found 0) <7> [438.732344] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [438.732604] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [438.732900] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [438.733182] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [438.733413] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 64800, found 0) <7> [438.733643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 64800, found 0) <7> [438.733910] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in port_clock (expected 64800, found 0) <7> [438.734179] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:72:pipe B] fastset requirement not met, forcing full modeset <7> [438.734410] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:72:pipe B] releasing PCH DPLL A <7> [438.734666] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:72:pipe B] min cdclk: 72000 kHz -> 0 kHz <7> [438.734942] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:72:pipe B] enable: no [modeset] <7> [438.735202] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:primary B] fb: [NOFB], visible: no <7> [438.735528] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B <7> [438.749046] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found <7> [438.749279] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found <7> [438.749500] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found <7> [438.765076] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x2, on? 1) for [CRTC:72:pipe B] <7> [438.765592] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A <7> [438.766327] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT] <7> [438.766584] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D] <7> [438.766852] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D] <7> [438.767102] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:73:VGA-1] <7> [438.767397] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:72:pipe B] <7> [438.767762] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A] <7> [438.767802] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:76:HDMI-A-1] <7> [438.767993] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [438.768288] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:53:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [438.768527] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3 <7> [438.768793] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [438.769044] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [438.769281] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [438.769518] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes) <7> [438.769776] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3) <7> [438.770031] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288) <7> [438.770262] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [438.770580] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [438.770865] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [438.771116] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [438.771345] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [438.771575] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [438.771858] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [438.772105] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [438.772334] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [438.772580] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [438.772842] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [438.773093] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [438.773323] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [438.773552] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [438.773812] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [438.774104] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [438.774334] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [438.774597] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [438.774887] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [438.775117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [438.775357] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [438.775587] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [438.775862] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [438.776104] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [438.776334] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [438.776563] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [438.776838] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [438.777069] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [438.777297] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [438.777544] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [438.777806] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [438.778060] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_infoframe (expected no, found yes) <7> [438.778291] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in dpll_hw_state <7> [438.778520] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [438.778779] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09 <7> [438.779064] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [438.779310] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06 <7> [438.779572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [438.779854] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800) <7> [438.780101] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800) <7> [438.780342] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in port_clock (expected 0, found 223200) <7> [438.780572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [438.780848] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [438.781107] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in avi infoframe <7> [438.781337] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [438.781566] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [438.781839] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [438.781844] i915 0000:00:02.0: colorspace: RGB <7> [438.781848] i915 0000:00:02.0: scan mode: Underscan <7> [438.781852] i915 0000:00:02.0: colorimetry: No Data <7> [438.781857] i915 0000:00:02.0: picture aspect: No Data <7> [438.781859] i915 0000:00:02.0: active aspect: Same as Picture <7> [438.781861] i915 0000:00:02.0: itc: No Data <7> [438.781863] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [438.781865] i915 0000:00:02.0: quantization range: Full <7> [438.781866] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [438.781868] i915 0000:00:02.0: video code: 0 <7> [438.781870] i915 0000:00:02.0: ycc quantization range: Full <7> [438.781872] i915 0000:00:02.0: hdmi content type: Graphics <7> [438.781874] i915 0000:00:02.0: pixel repeat: 0 <7> [438.781876] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [438.781879] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in spd infoframe <7> [438.782126] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [438.782370] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [438.782599] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [438.782601] i915 0000:00:02.0: vendor: Intel <7> [438.782603] i915 0000:00:02.0: product: Integrated gfx <7> [438.782605] i915 0000:00:02.0: source device information: PC General (0x9) <7> [438.782608] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hdmi infoframe <7> [438.782876] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [438.783117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [438.783344] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [438.783347] i915 0000:00:02.0: empty frame <7> [438.783350] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:53:pipe A] fastset requirement not met, forcing full modeset <7> [438.783611] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:53:pipe A] min cdclk: 0 kHz -> 165334 kHz <7> [438.783893] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:53:pipe A] allocated PCH DPLL A <7> [438.784177] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:53:pipe A] reserving PCH DPLL A <7> [438.784408] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:53:pipe A] enable: yes [modeset] <7> [438.784672] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [438.784956] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0 <7> [438.784950] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on <7> [438.785202] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [438.785441] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [438.785670] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [438.786015] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [438.786244] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64 <7> [438.786473] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [438.786703] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [438.786980] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [438.786982] i915 0000:00:02.0: colorspace: RGB <7> [438.786984] i915 0000:00:02.0: scan mode: Underscan <7> [438.786986] i915 0000:00:02.0: colorimetry: No Data <7> [438.786988] i915 0000:00:02.0: picture aspect: No Data <7> [438.786990] i915 0000:00:02.0: active aspect: Same as Picture <7> [438.786992] i915 0000:00:02.0: itc: No Data <7> [438.787002] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [438.787004] i915 0000:00:02.0: quantization range: Full <7> [438.787006] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [438.787008] i915 0000:00:02.0: video code: 0 <7> [438.787010] i915 0000:00:02.0: ycc quantization range: Full <7> [438.787012] i915 0000:00:02.0: hdmi content type: Graphics <7> [438.787013] i915 0000:00:02.0: pixel repeat: 0 <7> [438.787015] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [438.787018] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [438.787020] i915 0000:00:02.0: vendor: Intel <7> [438.787022] i915 0000:00:02.0: product: Integrated gfx <7> [438.787024] i915 0000:00:02.0: source device information: PC General (0x9) <7> [438.787027] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [438.787029] i915 0000:00:02.0: empty frame <7> [438.787031] 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> [438.787269] 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> [438.787512] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1 <7> [438.787749] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [438.788003] 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> [438.788242] 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> [438.788469] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [438.788697] 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> [438.788998] 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> [438.789253] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [438.789517] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [438.789795] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [438.790037] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pixel rate 148800, min cdclk 165334, min voltage level 0 <7> [438.790277] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0 <7> [438.790505] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [438.790733] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [438.791001] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [438.791259] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [438.791487] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06 <7> [438.791714] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [438.791987] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [438.792232] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [438.792460] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [438.792703] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [438.792989] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [438.793234] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:primary A] fb: [FB:90] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [438.793465] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [438.793692] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [438.796055] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on <7> [438.796310] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT] <7> [438.796571] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D] <7> [438.796856] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D] <7> [438.797682] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [438.798772] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100 <7> [438.799008] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done. <7> [438.799932] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x600 <7> [438.800159] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done. <7> [438.800389] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done. <7> [438.800617] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:53:pipe A] <7> [438.800892] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A <7> [438.869246] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:76:HDMI-A-1][ENCODER:75:HDMI D] Enable audio codec on [CRTC:53:pipe A], 32 bytes ELD <7> [438.885837] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults <7> [438.886339] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000) <7> [438.886891] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:76:HDMI-A-1] <7> [438.887638] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:53:pipe A] <6> [442.570615] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL

Detail

Value

Duration

3.90 seconds

Hostname

shard-snb6

Igt-Version

IGT-Version: 2.4-g3ef61dd87 (x86_64) (Linux: 7.1.0-rc2-CI_DRM_18408-ge798c5cca30e+ x86_64)

Out

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

Err

Starting dynamic subtest: A-HDMI-A1
(kms_flip:2775) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2775) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-HDMI-A1 failed.
**** DEBUG ****
(kms_flip:2775) DEBUG: name = flip
last_ts = 439.896240
last_received_ts = 439.895813
last_seq = 10134
current_ts = 439.912872
current_received_ts = 439.912415
current_seq = 10135
count = 79
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 7us
(kms_flip:2775) DEBUG: name = flip
last_ts = 439.912872
last_received_ts = 439.912415
last_seq = 10135
current_ts = 439.929504
current_received_ts = 439.929077
current_seq = 10136
count = 80
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 7us
(kms_flip:2775) DEBUG: name = flip
last_ts = 439.929504
last_received_ts = 439.929077
last_seq = 10136
current_ts = 439.946136
current_received_ts = 439.945679
current_seq = 10137
count = 81
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 439.946136
last_received_ts = 439.945679
last_seq = 10137
current_ts = 439.962769
current_received_ts = 439.962311
current_seq = 10138
count = 82
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 439.962769
last_received_ts = 439.962311
last_seq = 10138
current_ts = 439.979401
current_received_ts = 439.978943
current_seq = 10139
count = 83
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 439.979401
last_received_ts = 439.978943
last_seq = 10139
current_ts = 439.996033
current_received_ts = 439.995605
current_seq = 10140
count = 84
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 439.996033
last_received_ts = 439.995605
last_seq = 10140
current_ts = 440.012665
current_received_ts = 440.012238
current_seq = 10141
count = 85
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.012665
last_received_ts = 440.012238
last_seq = 10141
current_ts = 440.029297
current_received_ts = 440.028778
current_seq = 10142
count = 86
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.029297
last_received_ts = 440.028778
last_seq = 10142
current_ts = 440.045929
current_received_ts = 440.045471
current_seq = 10143
count = 87
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.045929
last_received_ts = 440.045471
last_seq = 10143
current_ts = 440.062561
current_received_ts = 440.062103
current_seq = 10144
count = 88
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.062561
last_received_ts = 440.062103
last_seq = 10144
current_ts = 440.079193
current_received_ts = 440.078766
current_seq = 10145
count = 89
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.079193
last_received_ts = 440.078766
last_seq = 10145
current_ts = 440.095825
current_received_ts = 440.095398
current_seq = 10146
count = 90
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.095825
last_received_ts = 440.095398
last_seq = 10146
current_ts = 440.112457
current_received_ts = 440.112061
current_seq = 10147
count = 91
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.112457
last_received_ts = 440.112061
last_seq = 10147
current_ts = 440.129089
current_received_ts = 440.128662
current_seq = 10148
count = 92
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.129089
last_received_ts = 440.128662
last_seq = 10148
current_ts = 440.145721
current_received_ts = 440.145294
current_seq = 10149
count = 93
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.145721
last_received_ts = 440.145294
last_seq = 10149
current_ts = 440.162354
current_received_ts = 440.161926
current_seq = 10150
count = 94
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.162354
last_received_ts = 440.161926
last_seq = 10150
current_ts = 440.178986
current_received_ts = 440.178528
current_seq = 10151
count = 95
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.178986
last_received_ts = 440.178528
last_seq = 10151
current_ts = 440.195618
current_received_ts = 440.195160
current_seq = 10152
count = 96
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.195618
last_received_ts = 440.195160
last_seq = 10152
current_ts = 440.212250
current_received_ts = 440.211792
current_seq = 10153
count = 97
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.212250
last_received_ts = 440.211792
last_seq = 10153
current_ts = 440.228882
current_received_ts = 440.228424
current_seq = 10154
count = 98
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.228882
last_received_ts = 440.228424
last_seq = 10154
current_ts = 440.245514
current_received_ts = 440.245117
current_seq = 10155
count = 99
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.245514
last_received_ts = 440.245117
last_seq = 10155
current_ts = 440.262146
current_received_ts = 440.261719
current_seq = 10156
count = 100
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.262146
last_received_ts = 440.261719
last_seq = 10156
current_ts = 440.278778
current_received_ts = 440.278351
current_seq = 10157
count = 101
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.278778
last_received_ts = 440.278351
last_seq = 10157
current_ts = 440.295410
current_received_ts = 440.294983
current_seq = 10158
count = 102
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.295410
last_received_ts = 440.294983
last_seq = 10158
current_ts = 440.312042
current_received_ts = 440.311615
current_seq = 10159
count = 103
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.312042
last_received_ts = 440.311615
last_seq = 10159
current_ts = 440.328674
current_received_ts = 440.328247
current_seq = 10160
count = 104
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.328674
last_received_ts = 440.328247
last_seq = 10160
current_ts = 440.345306
current_received_ts = 440.344879
current_seq = 10161
count = 105
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.345306
last_received_ts = 440.344879
last_seq = 10161
current_ts = 440.361938
current_received_ts = 440.361511
current_seq = 10162
count = 106
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.361938
last_received_ts = 440.361511
last_seq = 10162
current_ts = 440.378601
current_received_ts = 440.378143
current_seq = 10163
count = 107
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.378601
last_received_ts = 440.378143
last_seq = 10163
current_ts = 440.395233
current_received_ts = 440.394775
current_seq = 10164
count = 108
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.395233
last_received_ts = 440.394775
last_seq = 10164
current_ts = 440.411865
current_received_ts = 440.411407
current_seq = 10165
count = 109
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.411865
last_received_ts = 440.411407
last_seq = 10165
current_ts = 440.428497
current_received_ts = 440.428070
current_seq = 10166
count = 110
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 7us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.428497
last_received_ts = 440.428070
last_seq = 10166
current_ts = 440.445129
current_received_ts = 440.444672
current_seq = 10167
count = 111
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.445129
last_received_ts = 440.444672
last_seq = 10167
current_ts = 440.461761
current_received_ts = 440.461304
current_seq = 10168
count = 112
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.461761
last_received_ts = 440.461304
last_seq = 10168
current_ts = 440.478394
current_received_ts = 440.477936
current_seq = 10169
count = 113
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.478394
last_received_ts = 440.477936
last_seq = 10169
current_ts = 440.495026
current_received_ts = 440.494568
current_seq = 10170
count = 114
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.495026
last_received_ts = 440.494568
last_seq = 10170
current_ts = 440.511658
current_received_ts = 440.511200
current_seq = 10171
count = 115
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.511658
last_received_ts = 440.511200
last_seq = 10171
current_ts = 440.528290
current_received_ts = 440.527802
current_seq = 10172
count = 116
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.528290
last_received_ts = 440.527802
last_seq = 10172
current_ts = 440.544922
current_received_ts = 440.544464
current_seq = 10173
count = 117
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.544922
last_received_ts = 440.544464
last_seq = 10173
current_ts = 440.561554
current_received_ts = 440.561096
current_seq = 10174
count = 118
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.561554
last_received_ts = 440.561096
last_seq = 10174
current_ts = 440.578186
current_received_ts = 440.577698
current_seq = 10175
count = 119
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.578186
last_received_ts = 440.577698
last_seq = 10175
current_ts = 440.594818
current_received_ts = 440.594391
current_seq = 10176
count = 120
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.594818
last_received_ts = 440.594391
last_seq = 10176
current_ts = 440.611450
current_received_ts = 440.611053
current_seq = 10177
count = 121
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.611450
last_received_ts = 440.611053
last_seq = 10177
current_ts = 440.628082
current_received_ts = 440.627625
current_seq = 10178
count = 122
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.628082
last_received_ts = 440.627625
last_seq = 10178
current_ts = 440.644714
current_received_ts = 440.644257
current_seq = 10179
count = 123
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.644714
last_received_ts = 440.644257
last_seq = 10179
current_ts = 440.661346
current_received_ts = 440.660889
current_seq = 10180
count = 124
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.661346
last_received_ts = 440.660889
last_seq = 10180
current_ts = 440.677979
current_received_ts = 440.677551
current_seq = 10181
count = 125
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.677979
last_received_ts = 440.677551
last_seq = 10181
current_ts = 440.694611
current_received_ts = 440.694061
current_seq = 10182
count = 126
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.694611
last_received_ts = 440.694061
last_seq = 10182
current_ts = 440.711243
current_received_ts = 440.710663
current_seq = 10183
count = 127
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 5us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.711243
last_received_ts = 440.710663
last_seq = 10183
current_ts = 440.727875
current_received_ts = 440.727325
current_seq = 10184
count = 128
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 5us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.727875
last_received_ts = 440.727325
last_seq = 10184
current_ts = 440.744507
current_received_ts = 440.743896
current_seq = 10185
count = 129
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 5us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.744507
last_received_ts = 440.743896
last_seq = 10185
current_ts = 440.761139
current_received_ts = 440.760590
current_seq = 10186
count = 130
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 5us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.761139
last_received_ts = 440.760590
last_seq = 10186
current_ts = 440.777771
current_received_ts = 440.777283
current_seq = 10187
count = 131
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.777771
last_received_ts = 440.777283
last_seq = 10187
current_ts = 440.794403
current_received_ts = 440.793976
current_seq = 10188
count = 132
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 36us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.794403
last_received_ts = 440.793976
last_seq = 10188
current_ts = 440.811035
current_received_ts = 440.810608
current_seq = 10189
count = 133
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.811035
last_received_ts = 440.810608
last_seq = 10189
current_ts = 440.827667
current_received_ts = 440.827209
current_seq = 10190
count = 134
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.827667
last_received_ts = 440.827209
last_seq = 10190
current_ts = 440.844299
current_received_ts = 440.843872
current_seq = 10191
count = 135
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 6us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.844299
last_received_ts = 440.843872
last_seq = 10191
current_ts = 440.860931
current_received_ts = 440.860504
current_seq = 10192
count = 136
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.860931
last_received_ts = 440.860504
last_seq = 10192
current_ts = 440.877563
current_received_ts = 440.877106
current_seq = 10193
count = 137
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.877563
last_received_ts = 440.877106
last_seq = 10193
current_ts = 440.894196
current_received_ts = 440.893768
current_seq = 10194
count = 138
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.894196
last_received_ts = 440.893768
last_seq = 10194
current_ts = 440.910828
current_received_ts = 440.910400
current_seq = 10195
count = 139
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.910828
last_received_ts = 440.910400
last_seq = 10195
current_ts = 440.927460
current_received_ts = 440.927124
current_seq = 10196
count = 140
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.927460
last_received_ts = 440.927124
last_seq = 10196
current_ts = 440.944092
current_received_ts = 440.943695
current_seq = 10197
count = 141
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.944092
last_received_ts = 440.943695
last_seq = 10197
current_ts = 440.960724
current_received_ts = 440.960327
current_seq = 10198
count = 142
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 7us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.960724
last_received_ts = 440.960327
last_seq = 10198
current_ts = 440.977356
current_received_ts = 440.976929
current_seq = 10199
count = 143
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.977356
last_received_ts = 440.976929
last_seq = 10199
current_ts = 440.994019
current_received_ts = 440.993591
current_seq = 10200
count = 144
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 7us
(kms_flip:2775) DEBUG: name = flip
last_ts = 440.994019
last_received_ts = 440.993591
last_seq = 10200
current_ts = 441.010651
current_received_ts = 441.010193
current_seq = 10201
count = 145
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.010651
last_received_ts = 441.010193
last_seq = 10201
current_ts = 441.027283
current_received_ts = 441.026794
current_seq = 10202
count = 146
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.027283
last_received_ts = 441.026794
last_seq = 10202
current_ts = 441.043915
current_received_ts = 441.043457
current_seq = 10203
count = 147
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.043915
last_received_ts = 441.043457
last_seq = 10203
current_ts = 441.060547
current_received_ts = 441.060120
current_seq = 10204
count = 148
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.060547
last_received_ts = 441.060120
last_seq = 10204
current_ts = 441.077179
current_received_ts = 441.076752
current_seq = 10205
count = 149
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.077179
last_received_ts = 441.076752
last_seq = 10205
current_ts = 441.093811
current_received_ts = 441.093384
current_seq = 10206
count = 150
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.093811
last_received_ts = 441.093384
last_seq = 10206
current_ts = 441.110443
current_received_ts = 441.109985
current_seq = 10207
count = 151
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.110443
last_received_ts = 441.109985
last_seq = 10207
current_ts = 441.127075
current_received_ts = 441.126617
current_seq = 10208
count = 152
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.127075
last_received_ts = 441.126617
last_seq = 10208
current_ts = 441.143707
current_received_ts = 441.143250
current_seq = 10209
count = 153
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.143707
last_received_ts = 441.143250
last_seq = 10209
current_ts = 441.160339
current_received_ts = 441.159882
current_seq = 10210
count = 154
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.160339
last_received_ts = 441.159882
last_seq = 10210
current_ts = 441.176971
current_received_ts = 441.176514
current_seq = 10211
count = 155
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.176971
last_received_ts = 441.176514
last_seq = 10211
current_ts = 441.193604
current_received_ts = 441.193146
current_seq = 10212
count = 156
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.193604
last_received_ts = 441.193146
last_seq = 10212
current_ts = 441.210236
current_received_ts = 441.209778
current_seq = 10213
count = 157
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.210236
last_received_ts = 441.209778
last_seq = 10213
current_ts = 441.226868
current_received_ts = 441.226410
current_seq = 10214
count = 158
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.226868
last_received_ts = 441.226410
last_seq = 10214
current_ts = 441.243500
current_received_ts = 441.243103
current_seq = 10215
count = 159
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.243500
last_received_ts = 441.243103
last_seq = 10215
current_ts = 441.260132
current_received_ts = 441.259674
current_seq = 10216
count = 160
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.260132
last_received_ts = 441.259674
last_seq = 10216
current_ts = 441.276764
current_received_ts = 441.276306
current_seq = 10217
count = 161
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.276764
last_received_ts = 441.276306
last_seq = 10217
current_ts = 441.293396
current_received_ts = 441.292969
current_seq = 10218
count = 162
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.293396
last_received_ts = 441.292969
last_seq = 10218
current_ts = 441.310028
current_received_ts = 441.309601
current_seq = 10219
count = 163
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.310028
last_received_ts = 441.309601
last_seq = 10219
current_ts = 441.326660
current_received_ts = 441.326233
current_seq = 10220
count = 164
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.326660
last_received_ts = 441.326233
last_seq = 10220
current_ts = 441.343292
current_received_ts = 441.342834
current_seq = 10221
count = 165
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.343292
last_received_ts = 441.342834
last_seq = 10221
current_ts = 441.359924
current_received_ts = 441.359497
current_seq = 10222
count = 166
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.359924
last_received_ts = 441.359497
last_seq = 10222
current_ts = 441.376556
current_received_ts = 441.376099
current_seq = 10223
count = 167
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.376556
last_received_ts = 441.376099
last_seq = 10223
current_ts = 441.393188
current_received_ts = 441.392761
current_seq = 10224
count = 168
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.393188
last_received_ts = 441.392761
last_seq = 10224
current_ts = 441.409821
current_received_ts = 441.409393
current_seq = 10225
count = 169
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.409821
last_received_ts = 441.409393
last_seq = 10225
current_ts = 441.426453
current_received_ts = 441.426025
current_seq = 10226
count = 170
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.426453
last_received_ts = 441.426025
last_seq = 10226
current_ts = 441.443085
current_received_ts = 441.442657
current_seq = 10227
count = 171
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 6us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.443085
last_received_ts = 441.442657
last_seq = 10227
current_ts = 441.459717
current_received_ts = 441.459290
current_seq = 10228
count = 172
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.459717
last_received_ts = 441.459290
last_seq = 10228
current_ts = 441.476349
current_received_ts = 441.475922
current_seq = 10229
count = 173
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.476349
last_received_ts = 441.475922
last_seq = 10229
current_ts = 441.492981
current_received_ts = 441.492554
current_seq = 10230
count = 174
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.492981
last_received_ts = 441.492554
last_seq = 10230
current_ts = 441.509613
current_received_ts = 441.509186
current_seq = 10231
count = 175
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.509613
last_received_ts = 441.509186
last_seq = 10231
current_ts = 441.526245
current_received_ts = 441.525787
current_seq = 10232
count = 176
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.526245
last_received_ts = 441.525787
last_seq = 10232
current_ts = 441.542877
current_received_ts = 441.542450
current_seq = 10233
count = 177
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.542877
last_received_ts = 441.542450
last_seq = 10233
current_ts = 441.559540
current_received_ts = 441.559052
current_seq = 10234
count = 178
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.559540
last_received_ts = 441.559052
last_seq = 10234
current_ts = 441.576172
current_received_ts = 441.575623
current_seq = 10235
count = 179
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.576172
last_received_ts = 441.575623
last_seq = 10235
current_ts = 441.592804
current_received_ts = 441.592346
current_seq = 10236
count = 180
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.592804
last_received_ts = 441.592346
last_seq = 10236
current_ts = 441.609436
current_received_ts = 441.608978
current_seq = 10237
count = 181
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.609436
last_received_ts = 441.608978
last_seq = 10237
current_ts = 441.626068
current_received_ts = 441.625641
current_seq = 10238
count = 182
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 7us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.626068
last_received_ts = 441.625641
last_seq = 10238
current_ts = 441.642700
current_received_ts = 441.642242
current_seq = 10239
count = 183
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.642700
last_received_ts = 441.642242
last_seq = 10239
current_ts = 441.659332
current_received_ts = 441.658875
current_seq = 10240
count = 184
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 7us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.659332
last_received_ts = 441.658875
last_seq = 10240
current_ts = 441.675964
current_received_ts = 441.675507
current_seq = 10241
count = 185
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.675964
last_received_ts = 441.675507
last_seq = 10241
current_ts = 441.692596
current_received_ts = 441.692139
current_seq = 10242
count = 186
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.692596
last_received_ts = 441.692139
last_seq = 10242
current_ts = 441.709229
current_received_ts = 441.708801
current_seq = 10243
count = 187
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.709229
last_received_ts = 441.708801
last_seq = 10243
current_ts = 441.725861
current_received_ts = 441.725403
current_seq = 10244
count = 188
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 9us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.725861
last_received_ts = 441.725403
last_seq = 10244
current_ts = 441.742493
current_received_ts = 441.742065
current_seq = 10245
count = 189
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.742493
last_received_ts = 441.742065
last_seq = 10245
current_ts = 441.759125
current_received_ts = 441.758698
current_seq = 10246
count = 190
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.759125
last_received_ts = 441.758698
last_seq = 10246
current_ts = 441.775757
current_received_ts = 441.775299
current_seq = 10247
count = 191
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.775757
last_received_ts = 441.775299
last_seq = 10247
current_ts = 441.792389
current_received_ts = 441.791962
current_seq = 10248
count = 192
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.792389
last_received_ts = 441.791962
last_seq = 10248
current_ts = 441.809021
current_received_ts = 441.808563
current_seq = 10249
count = 193
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.809021
last_received_ts = 441.808563
last_seq = 10249
current_ts = 441.825653
current_received_ts = 441.825195
current_seq = 10250
count = 194
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.825653
last_received_ts = 441.825195
last_seq = 10250
current_ts = 441.842285
current_received_ts = 441.841858
current_seq = 10251
count = 195
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 6us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.842285
last_received_ts = 441.841858
last_seq = 10251
current_ts = 441.858917
current_received_ts = 441.858490
current_seq = 10252
count = 196
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.858917
last_received_ts = 441.858490
last_seq = 10252
current_ts = 441.875549
current_received_ts = 441.875122
current_seq = 10253
count = 197
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.875549
last_received_ts = 441.875122
last_seq = 10253
current_ts = 441.892181
current_received_ts = 441.891754
current_seq = 10254
count = 198
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.892181
last_received_ts = 441.891754
last_seq = 10254
current_ts = 441.908813
current_received_ts = 441.908386
current_seq = 10255
count = 199
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 8us
(kms_flip:2775) DEBUG: name = flip
last_ts = 441.908813
last_received_ts = 441.908386
last_seq = 10255
current_ts = 441.925446
current_received_ts = 441.924988
current_seq = 10256
count = 200
seq_step = 1
(kms_flip:2775) DEBUG: Vblank took 514us
(kms_flip:2775) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2775) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2775) igt_core-INFO: Stack trace:
(kms_flip:2775) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2775) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2775) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2775) igt_core-INFO:   #3 ../tests/kms_flip.c:2184 __igt_unique____real_main2105()
(kms_flip:2775) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2775) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2775) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2775) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A1: FAIL (3.902s)

Dmesg

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [438.787031] 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> [438.787269] 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> [438.787512] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1

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

<7> [438.788003] 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> [438.788242] 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> [438.788469] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [438.799932] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x600

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

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

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

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

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

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

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

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

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

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

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