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

Detail	Value
Duration	5.50 seconds
Hostname	shard-glk6
Igt-Version	IGT-Version: 2.3-g72b3f732c (x86_64) (Linux: 6.19.0-rc6-CI_DRM_17877-gab42b1c3fe4c+ x86_64)
Out	Starting dynamic subtest: B-HDMI-A2 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1889 run_test() #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045() #4 ../tests/kms_flip.c:2045 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest B-HDMI-A2: FAIL (5.505s)
Err	Starting dynamic subtest: B-HDMI-A2 (kms_flip:2543) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2543) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest B-HDMI-A2 failed. ** DEBUG (kms_flip:2543) DEBUG: name = flip last_ts = 455.694305 last_received_ts = 455.694153 last_seq = 11942 current_ts = 455.710968 current_received_ts = 455.710785 current_seq = 11943 count = 148 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 21us (kms_flip:2543) DEBUG: name = flip last_ts = 455.710968 last_received_ts = 455.710785 last_seq = 11943 current_ts = 455.727631 current_received_ts = 455.727386 current_seq = 11944 count = 149 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 455.727631 last_received_ts = 455.727386 last_seq = 11944 current_ts = 455.744293 current_received_ts = 455.744202 current_seq = 11945 count = 150 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 22us (kms_flip:2543) DEBUG: name = flip last_ts = 455.744293 last_received_ts = 455.744202 last_seq = 11945 current_ts = 455.760956 current_received_ts = 455.760925 current_seq = 11946 count = 151 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 22us (kms_flip:2543) DEBUG: name = flip last_ts = 455.760956 last_received_ts = 455.760925 last_seq = 11946 current_ts = 455.777618 current_received_ts = 455.777466 current_seq = 11947 count = 152 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 455.777618 last_received_ts = 455.777466 last_seq = 11947 current_ts = 455.794281 current_received_ts = 455.794159 current_seq = 11948 count = 153 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 455.794281 last_received_ts = 455.794159 last_seq = 11948 current_ts = 455.810974 current_received_ts = 455.810791 current_seq = 11949 count = 154 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 22us (kms_flip:2543) DEBUG: name = flip last_ts = 455.810974 last_received_ts = 455.810791 last_seq = 11949 current_ts = 455.827637 current_received_ts = 455.827545 current_seq = 11950 count = 155 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 455.827637 last_received_ts = 455.827545 last_seq = 11950 current_ts = 455.844299 current_received_ts = 455.843811 current_seq = 11951 count = 156 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 455.844299 last_received_ts = 455.843811 last_seq = 11951 current_ts = 455.860962 current_received_ts = 455.860779 current_seq = 11952 count = 157 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 21us (kms_flip:2543) DEBUG: name = flip last_ts = 455.860962 last_received_ts = 455.860779 last_seq = 11952 current_ts = 455.877625 current_received_ts = 455.877472 current_seq = 11953 count = 158 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 455.877625 last_received_ts = 455.877472 last_seq = 11953 current_ts = 455.894287 current_received_ts = 455.894165 current_seq = 11954 count = 159 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 455.894287 last_received_ts = 455.894165 last_seq = 11954 current_ts = 455.910950 current_received_ts = 455.910797 current_seq = 11955 count = 160 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 21us (kms_flip:2543) DEBUG: name = flip last_ts = 455.910950 last_received_ts = 455.910797 last_seq = 11955 current_ts = 455.927612 current_received_ts = 455.927460 current_seq = 11956 count = 161 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 455.927612 last_received_ts = 455.927460 last_seq = 11956 current_ts = 455.944275 current_received_ts = 455.944183 current_seq = 11957 count = 162 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 455.944275 last_received_ts = 455.944183 last_seq = 11957 current_ts = 455.960968 current_received_ts = 455.960785 current_seq = 11958 count = 163 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 21us (kms_flip:2543) DEBUG: name = flip last_ts = 455.960968 last_received_ts = 455.960785 last_seq = 11958 current_ts = 455.977631 current_received_ts = 455.977539 current_seq = 11959 count = 164 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 455.977631 last_received_ts = 455.977539 last_seq = 11959 current_ts = 455.994293 current_received_ts = 455.994202 current_seq = 11960 count = 165 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 455.994293 last_received_ts = 455.994202 last_seq = 11960 current_ts = 456.010956 current_received_ts = 456.010773 current_seq = 11961 count = 166 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 21us (kms_flip:2543) DEBUG: name = flip last_ts = 456.010956 last_received_ts = 456.010773 last_seq = 11961 current_ts = 456.027618 current_received_ts = 456.027466 current_seq = 11962 count = 167 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.027618 last_received_ts = 456.027466 last_seq = 11962 current_ts = 456.044312 current_received_ts = 456.044189 current_seq = 11963 count = 168 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 456.044312 last_received_ts = 456.044189 last_seq = 11963 current_ts = 456.060974 current_received_ts = 456.060852 current_seq = 11964 count = 169 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.060974 last_received_ts = 456.060852 last_seq = 11964 current_ts = 456.077637 current_received_ts = 456.077545 current_seq = 11965 count = 170 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.077637 last_received_ts = 456.077545 last_seq = 11965 current_ts = 456.094299 current_received_ts = 456.094208 current_seq = 11966 count = 171 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.094299 last_received_ts = 456.094208 last_seq = 11966 current_ts = 456.110962 current_received_ts = 456.110779 current_seq = 11967 count = 172 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 20us (kms_flip:2543) DEBUG: name = flip last_ts = 456.110962 last_received_ts = 456.110779 last_seq = 11967 current_ts = 456.127625 current_received_ts = 456.127472 current_seq = 11968 count = 173 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.127625 last_received_ts = 456.127472 last_seq = 11968 current_ts = 456.144287 current_received_ts = 456.144165 current_seq = 11969 count = 174 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.144287 last_received_ts = 456.144165 last_seq = 11969 current_ts = 456.160980 current_received_ts = 456.160828 current_seq = 11970 count = 175 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.160980 last_received_ts = 456.160828 last_seq = 11970 current_ts = 456.177643 current_received_ts = 456.177521 current_seq = 11971 count = 176 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.177643 last_received_ts = 456.177521 last_seq = 11971 current_ts = 456.194305 current_received_ts = 456.194122 current_seq = 11972 count = 177 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.194305 last_received_ts = 456.194122 last_seq = 11972 current_ts = 456.210968 current_received_ts = 456.210815 current_seq = 11973 count = 178 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 18us (kms_flip:2543) DEBUG: name = flip last_ts = 456.210968 last_received_ts = 456.210815 last_seq = 11973 current_ts = 456.227631 current_received_ts = 456.227356 current_seq = 11974 count = 179 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.227631 last_received_ts = 456.227356 last_seq = 11974 current_ts = 456.244293 current_received_ts = 456.244171 current_seq = 11975 count = 180 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.244293 last_received_ts = 456.244171 last_seq = 11975 current_ts = 456.260956 current_received_ts = 456.260864 current_seq = 11976 count = 181 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.260956 last_received_ts = 456.260864 last_seq = 11976 current_ts = 456.277618 current_received_ts = 456.277466 current_seq = 11977 count = 182 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.277618 last_received_ts = 456.277466 last_seq = 11977 current_ts = 456.294312 current_received_ts = 456.294403 current_seq = 11978 count = 183 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 23us (kms_flip:2543) DEBUG: name = flip last_ts = 456.294312 last_received_ts = 456.294403 last_seq = 11978 current_ts = 456.310974 current_received_ts = 456.310883 current_seq = 11979 count = 184 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 456.310974 last_received_ts = 456.310883 last_seq = 11979 current_ts = 456.327637 current_received_ts = 456.327393 current_seq = 11980 count = 185 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.327637 last_received_ts = 456.327393 last_seq = 11980 current_ts = 456.344299 current_received_ts = 456.344116 current_seq = 11981 count = 186 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.344299 last_received_ts = 456.344116 last_seq = 11981 current_ts = 456.360962 current_received_ts = 456.360779 current_seq = 11982 count = 187 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 23us (kms_flip:2543) DEBUG: name = flip last_ts = 456.360962 last_received_ts = 456.360779 last_seq = 11982 current_ts = 456.377625 current_received_ts = 456.377533 current_seq = 11983 count = 188 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.377625 last_received_ts = 456.377533 last_seq = 11983 current_ts = 456.394287 current_received_ts = 456.394104 current_seq = 11984 count = 189 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.394287 last_received_ts = 456.394104 last_seq = 11984 current_ts = 456.410950 current_received_ts = 456.410858 current_seq = 11985 count = 190 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.410950 last_received_ts = 456.410858 last_seq = 11985 current_ts = 456.427643 current_received_ts = 456.427521 current_seq = 11986 count = 191 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.427643 last_received_ts = 456.427521 last_seq = 11986 current_ts = 456.444305 current_received_ts = 456.444092 current_seq = 11987 count = 192 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.444305 last_received_ts = 456.444092 last_seq = 11987 current_ts = 456.460968 current_received_ts = 456.460876 current_seq = 11988 count = 193 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.460968 last_received_ts = 456.460876 last_seq = 11988 current_ts = 456.477631 current_received_ts = 456.477539 current_seq = 11989 count = 194 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.477631 last_received_ts = 456.477539 last_seq = 11989 current_ts = 456.494293 current_received_ts = 456.494080 current_seq = 11990 count = 195 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.494293 last_received_ts = 456.494080 last_seq = 11990 current_ts = 456.510956 current_received_ts = 456.510864 current_seq = 11991 count = 196 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.510956 last_received_ts = 456.510864 last_seq = 11991 current_ts = 456.527649 current_received_ts = 456.527496 current_seq = 11992 count = 197 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.527649 last_received_ts = 456.527496 last_seq = 11992 current_ts = 456.544312 current_received_ts = 456.544098 current_seq = 11993 count = 198 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.544312 last_received_ts = 456.544098 last_seq = 11993 current_ts = 456.560974 current_received_ts = 456.560852 current_seq = 11994 count = 199 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 456.560974 last_received_ts = 456.560852 last_seq = 11994 current_ts = 456.577637 current_received_ts = 456.577545 current_seq = 11995 count = 200 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.577637 last_received_ts = 456.577545 last_seq = 11995 current_ts = 456.594299 current_received_ts = 456.594055 current_seq = 11996 count = 201 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.594299 last_received_ts = 456.594055 last_seq = 11996 current_ts = 456.610962 current_received_ts = 456.610809 current_seq = 11997 count = 202 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 22us (kms_flip:2543) DEBUG: name = flip last_ts = 456.610962 last_received_ts = 456.610809 last_seq = 11997 current_ts = 456.627655 current_received_ts = 456.627350 current_seq = 11998 count = 203 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.627655 last_received_ts = 456.627350 last_seq = 11998 current_ts = 456.644318 current_received_ts = 456.644104 current_seq = 11999 count = 204 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.644318 last_received_ts = 456.644104 last_seq = 11999 current_ts = 456.660980 current_received_ts = 456.660889 current_seq = 12000 count = 205 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.660980 last_received_ts = 456.660889 last_seq = 12000 current_ts = 456.677643 current_received_ts = 456.677490 current_seq = 12001 count = 206 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.677643 last_received_ts = 456.677490 last_seq = 12001 current_ts = 456.694305 current_received_ts = 456.694092 current_seq = 12002 count = 207 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.694305 last_received_ts = 456.694092 last_seq = 12002 current_ts = 456.710968 current_received_ts = 456.710815 current_seq = 12003 count = 208 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.710968 last_received_ts = 456.710815 last_seq = 12003 current_ts = 456.727631 current_received_ts = 456.727417 current_seq = 12004 count = 209 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.727631 last_received_ts = 456.727417 last_seq = 12004 current_ts = 456.744293 current_received_ts = 456.744080 current_seq = 12005 count = 210 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.744293 last_received_ts = 456.744080 last_seq = 12005 current_ts = 456.760986 current_received_ts = 456.760864 current_seq = 12006 count = 211 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 456.760986 last_received_ts = 456.760864 last_seq = 12006 current_ts = 456.777649 current_received_ts = 456.777435 current_seq = 12007 count = 212 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.777649 last_received_ts = 456.777435 last_seq = 12007 current_ts = 456.794312 current_received_ts = 456.794220 current_seq = 12008 count = 213 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.794312 last_received_ts = 456.794220 last_seq = 12008 current_ts = 456.810974 current_received_ts = 456.810822 current_seq = 12009 count = 214 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 20us (kms_flip:2543) DEBUG: name = flip last_ts = 456.810974 last_received_ts = 456.810822 last_seq = 12009 current_ts = 456.827637 current_received_ts = 456.827484 current_seq = 12010 count = 215 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.827637 last_received_ts = 456.827484 last_seq = 12010 current_ts = 456.844299 current_received_ts = 456.844177 current_seq = 12011 count = 216 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.844299 last_received_ts = 456.844177 last_seq = 12011 current_ts = 456.860962 current_received_ts = 456.860809 current_seq = 12012 count = 217 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 22us (kms_flip:2543) DEBUG: name = flip last_ts = 456.860962 last_received_ts = 456.860809 last_seq = 12012 current_ts = 456.877655 current_received_ts = 456.877533 current_seq = 12013 count = 218 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.877655 last_received_ts = 456.877533 last_seq = 12013 current_ts = 456.894318 current_received_ts = 456.894104 current_seq = 12014 count = 219 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.894318 last_received_ts = 456.894104 last_seq = 12014 current_ts = 456.910980 current_received_ts = 456.910858 current_seq = 12015 count = 220 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.910980 last_received_ts = 456.910858 last_seq = 12015 current_ts = 456.927643 current_received_ts = 456.927490 current_seq = 12016 count = 221 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.927643 last_received_ts = 456.927490 last_seq = 12016 current_ts = 456.944305 current_received_ts = 456.944183 current_seq = 12017 count = 222 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 16us (kms_flip:2543) DEBUG: name = flip last_ts = 456.944305 last_received_ts = 456.944183 last_seq = 12017 current_ts = 456.960968 current_received_ts = 456.960876 current_seq = 12018 count = 223 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.960968 last_received_ts = 456.960876 last_seq = 12018 current_ts = 456.977631 current_received_ts = 456.977539 current_seq = 12019 count = 224 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 456.977631 last_received_ts = 456.977539 last_seq = 12019 current_ts = 456.994293 current_received_ts = 456.994110 current_seq = 12020 count = 225 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 456.994293 last_received_ts = 456.994110 last_seq = 12020 current_ts = 457.010986 current_received_ts = 457.010803 current_seq = 12021 count = 226 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 22us (kms_flip:2543) DEBUG: name = flip last_ts = 457.010986 last_received_ts = 457.010803 last_seq = 12021 current_ts = 457.027649 current_received_ts = 457.027557 current_seq = 12022 count = 227 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.027649 last_received_ts = 457.027557 last_seq = 12022 current_ts = 457.044312 current_received_ts = 457.044098 current_seq = 12023 count = 228 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.044312 last_received_ts = 457.044098 last_seq = 12023 current_ts = 457.060974 current_received_ts = 457.060791 current_seq = 12024 count = 229 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.060974 last_received_ts = 457.060791 last_seq = 12024 current_ts = 457.077637 current_received_ts = 457.077545 current_seq = 12025 count = 230 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.077637 last_received_ts = 457.077545 last_seq = 12025 current_ts = 457.094299 current_received_ts = 457.094116 current_seq = 12026 count = 231 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 457.094299 last_received_ts = 457.094116 last_seq = 12026 current_ts = 457.110992 current_received_ts = 457.110901 current_seq = 12027 count = 232 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.110992 last_received_ts = 457.110901 last_seq = 12027 current_ts = 457.127655 current_received_ts = 457.127472 current_seq = 12028 count = 233 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.127655 last_received_ts = 457.127472 last_seq = 12028 current_ts = 457.144318 current_received_ts = 457.144165 current_seq = 12029 count = 234 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 18us (kms_flip:2543) DEBUG: name = flip last_ts = 457.144318 last_received_ts = 457.144165 last_seq = 12029 current_ts = 457.160980 current_received_ts = 457.160858 current_seq = 12030 count = 235 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.160980 last_received_ts = 457.160858 last_seq = 12030 current_ts = 457.177643 current_received_ts = 457.177521 current_seq = 12031 count = 236 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 457.177643 last_received_ts = 457.177521 last_seq = 12031 current_ts = 457.194305 current_received_ts = 457.194122 current_seq = 12032 count = 237 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.194305 last_received_ts = 457.194122 last_seq = 12032 current_ts = 457.210999 current_received_ts = 457.210815 current_seq = 12033 count = 238 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 20us (kms_flip:2543) DEBUG: name = flip last_ts = 457.210999 last_received_ts = 457.210815 last_seq = 12033 current_ts = 457.227661 current_received_ts = 457.227814 current_seq = 12034 count = 239 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 21us (kms_flip:2543) DEBUG: name = flip last_ts = 457.227661 last_received_ts = 457.227814 last_seq = 12034 current_ts = 457.244324 current_received_ts = 457.244202 current_seq = 12035 count = 240 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 457.244324 last_received_ts = 457.244202 last_seq = 12035 current_ts = 457.260986 current_received_ts = 457.260864 current_seq = 12036 count = 241 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.260986 last_received_ts = 457.260864 last_seq = 12036 current_ts = 457.277649 current_received_ts = 457.277557 current_seq = 12037 count = 242 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.277649 last_received_ts = 457.277557 last_seq = 12037 current_ts = 457.294312 current_received_ts = 457.294189 current_seq = 12038 count = 243 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 457.294312 last_received_ts = 457.294189 last_seq = 12038 current_ts = 457.310974 current_received_ts = 457.310791 current_seq = 12039 count = 244 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 21us (kms_flip:2543) DEBUG: name = flip last_ts = 457.310974 last_received_ts = 457.310791 last_seq = 12039 current_ts = 457.327637 current_received_ts = 457.327423 current_seq = 12040 count = 245 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.327637 last_received_ts = 457.327423 last_seq = 12040 current_ts = 457.344330 current_received_ts = 457.344208 current_seq = 12041 count = 246 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 457.344330 last_received_ts = 457.344208 last_seq = 12041 current_ts = 457.360992 current_received_ts = 457.360870 current_seq = 12042 count = 247 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.360992 last_received_ts = 457.360870 last_seq = 12042 current_ts = 457.377655 current_received_ts = 457.377563 current_seq = 12043 count = 248 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.377655 last_received_ts = 457.377563 last_seq = 12043 current_ts = 457.394318 current_received_ts = 457.394226 current_seq = 12044 count = 249 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 457.394318 last_received_ts = 457.394226 last_seq = 12044 current_ts = 457.410980 current_received_ts = 457.410889 current_seq = 12045 count = 250 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.410980 last_received_ts = 457.410889 last_seq = 12045 current_ts = 457.427643 current_received_ts = 457.427490 current_seq = 12046 count = 251 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.427643 last_received_ts = 457.427490 last_seq = 12046 current_ts = 457.444336 current_received_ts = 457.444153 current_seq = 12047 count = 252 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.444336 last_received_ts = 457.444153 last_seq = 12047 current_ts = 457.460968 current_received_ts = 457.460876 current_seq = 12048 count = 253 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 457.460968 last_received_ts = 457.460876 last_seq = 12048 current_ts = 457.477661 current_received_ts = 457.477478 current_seq = 12049 count = 254 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 21us (kms_flip:2543) DEBUG: name = flip last_ts = 457.477661 last_received_ts = 457.477478 last_seq = 12049 current_ts = 457.494324 current_received_ts = 457.494232 current_seq = 12050 count = 255 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.494324 last_received_ts = 457.494232 last_seq = 12050 current_ts = 457.510986 current_received_ts = 457.510834 current_seq = 12051 count = 256 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 20us (kms_flip:2543) DEBUG: name = flip last_ts = 457.510986 last_received_ts = 457.510834 last_seq = 12051 current_ts = 457.527649 current_received_ts = 457.527435 current_seq = 12052 count = 257 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 27us (kms_flip:2543) DEBUG: name = flip last_ts = 457.527649 last_received_ts = 457.527435 last_seq = 12052 current_ts = 457.544342 current_received_ts = 457.544128 current_seq = 12053 count = 258 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 17us (kms_flip:2543) DEBUG: name = flip last_ts = 457.544342 last_received_ts = 457.544128 last_seq = 12053 current_ts = 457.561005 current_received_ts = 457.560852 current_seq = 12054 count = 259 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 457.561005 last_received_ts = 457.560852 last_seq = 12054 current_ts = 457.577667 current_received_ts = 457.577545 current_seq = 12055 count = 260 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 25us (kms_flip:2543) DEBUG: name = flip last_ts = 457.577667 last_received_ts = 457.577545 last_seq = 12055 current_ts = 457.594330 current_received_ts = 457.594177 current_seq = 12056 count = 261 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.594330 last_received_ts = 457.594177 last_seq = 12056 current_ts = 457.610992 current_received_ts = 457.610901 current_seq = 12057 count = 262 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.610992 last_received_ts = 457.610901 last_seq = 12057 current_ts = 457.627655 current_received_ts = 457.627563 current_seq = 12058 count = 263 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.627655 last_received_ts = 457.627563 last_seq = 12058 current_ts = 457.644348 current_received_ts = 457.644226 current_seq = 12059 count = 264 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 457.644348 last_received_ts = 457.644226 last_seq = 12059 current_ts = 457.661011 current_received_ts = 457.660828 current_seq = 12060 count = 265 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 20us (kms_flip:2543) DEBUG: name = flip last_ts = 457.661011 last_received_ts = 457.660828 last_seq = 12060 current_ts = 457.677673 current_received_ts = 457.677551 current_seq = 12061 count = 266 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.677673 last_received_ts = 457.677551 last_seq = 12061 current_ts = 457.694336 current_received_ts = 457.694153 current_seq = 12062 count = 267 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 24us (kms_flip:2543) DEBUG: name = flip last_ts = 457.694336 last_received_ts = 457.694153 last_seq = 12062 current_ts = 457.710999 current_received_ts = 457.710876 current_seq = 12063 count = 268 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 26us (kms_flip:2543) DEBUG: name = flip last_ts = 457.710999 last_received_ts = 457.710876 last_seq = 12063 current_ts = 457.727661 current_received_ts = 457.727509 current_seq = 12064 count = 269 seq_step = 1 (kms_flip:2543) DEBUG: Vblank took 1015us (kms_flip:2543) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2543) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2543) igt_core-INFO: Stack trace: (kms_flip:2543) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2543) igt_core-INFO: #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() (kms_flip:2543) igt_core-INFO: #2 ../tests/kms_flip.c:1889 run_test() (kms_flip:2543) igt_core-INFO: #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045() (kms_flip:2543) igt_core-INFO: #4 ../tests/kms_flip.c:2045 main() (kms_flip:2543) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2543) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2543) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-HDMI-A2: FAIL (5.505s)
Dmesg	<6> [453.212962] [IGT] kms_flip: starting dynamic subtest B-HDMI-A2 <7> [453.214161] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:180] <7> [453.214498] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:184] <7> [453.269847] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:76:pipe A] <7> [453.270433] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [453.271539] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [453.272582] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [453.273607] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [453.274643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000) <7> [453.275646] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [453.276112] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [453.276486] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [453.276860] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [453.277264] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [453.277638] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [453.278055] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [453.278431] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [453.278802] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [453.279255] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [453.279637] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0) <7> [453.280029] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0) <7> [453.280461] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [453.280835] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [453.281237] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [453.281610] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [453.281983] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [453.282383] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [453.282778] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [453.283182] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [453.283555] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [453.283927] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [453.284326] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0) <7> [453.284698] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0) <7> [453.285096] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [453.285469] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [453.285842] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [453.286234] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [453.286610] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [453.286982] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in has_hdmi_sink (expected yes, found no) <7> [453.287387] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in has_infoframe (expected yes, found no) <7> [453.287764] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0) <7> [453.288150] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [453.288523] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [453.288896] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in port_clock (expected 222750, found 0) <7> [453.289308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000) <7> [453.289682] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000) <7> [453.290071] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in avi infoframe <7> [453.290445] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [453.290815] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [453.290819] i915 0000:00:02.0: colorspace: RGB <7> [453.290823] i915 0000:00:02.0: scan mode: Underscan <7> [453.290827] i915 0000:00:02.0: colorimetry: No Data <7> [453.290830] i915 0000:00:02.0: picture aspect: No Data <7> [453.290833] i915 0000:00:02.0: active aspect: Same as Picture <7> [453.290836] i915 0000:00:02.0: itc: No Data <7> [453.290840] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [453.290843] i915 0000:00:02.0: quantization range: Full <7> [453.290846] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [453.290849] i915 0000:00:02.0: video code: 0 <7> [453.290852] i915 0000:00:02.0: ycc quantization range: Full <7> [453.290856] i915 0000:00:02.0: hdmi content type: Graphics <7> [453.290859] i915 0000:00:02.0: pixel repeat: 0 <7> [453.290862] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [453.290865] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [453.291266] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in spd infoframe <7> [453.291642] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [453.292033] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [453.292037] i915 0000:00:02.0: vendor: Intel <7> [453.292040] i915 0000:00:02.0: product: Integrated gfx <7> [453.292044] i915 0000:00:02.0: source device information: PC General (0x9) <7> [453.292047] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [453.292422] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:76:pipe A] fastset requirement not met in hdmi infoframe <7> [453.292793] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [453.293193] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [453.293197] i915 0000:00:02.0: empty frame <7> [453.293200] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [453.293574] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:76:pipe A] fastset requirement not met, forcing full modeset <7> [453.293948] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:76:pipe A] releasing PORT PLL C <7> [453.294500] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:76:pipe A] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [453.294936] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:70:cursor A] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0 <7> [453.295416] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:76:pipe A] min cdclk: 192000 kHz -> 0 kHz <7> [453.295870] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [453.296270] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz <7> [453.296640] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4 <7> [453.297060] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:76:pipe A] enable: no [modeset] <7> [453.297441] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:plane 1A] fb: [NOFB], visible: no <7> [453.297815] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:43:plane 2A] fb: [NOFB], visible: no <7> [453.298216] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:52:plane 3A] fb: [NOFB], visible: no <7> [453.298587] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:61:plane 4A] fb: [NOFB], visible: no <7> [453.298957] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:70:cursor A] fb: [NOFB], visible: no <7> [453.299541] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:174:HDMI-A-2][ENCODER:173:DDI C/PHY C] Disable audio codec on [CRTC:76:pipe A] <7> [453.321788] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port C <7> [453.322706] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A <7> [453.335593] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10 <7> [453.340099] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time <7> [453.444520] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_C <7> [453.448093] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL C (active 0x1, on? 1) for [CRTC:76:pipe A] <7> [453.448839] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL C <7> [453.449582] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 79200 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 4 <7> [453.450039] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:163:DDI B/PHY B] <7> [453.450416] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:173:DDI C/PHY C] <7> [453.451033] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:174:HDMI-A-2] <7> [453.451627] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-c <7> [453.452283] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:76:pipe A] <7> [453.453561] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:119:pipe B] <7> [453.453921] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:162:pipe C] <7> [453.454571] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:119:pipe B] <7> [453.454614] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [453.455134] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz <7> [453.455519] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13 <7> [453.456562] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 316800 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 13 <7> [453.457222] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:174:HDMI-A-2] <7> [453.457427] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [453.457848] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:119:pipe B] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [453.458268] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:173:DDI C/PHY C] [CRTC:119:pipe B] <7> [453.458634] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.enable (expected no, found yes) <7> [453.459044] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.active (expected no, found yes) <7> [453.459416] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1) <7> [453.459788] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in lane_count (expected 0, found 4) <7> [453.460195] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d) <7> [453.460569] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [453.460943] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [453.461356] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [453.461733] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [453.462141] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [453.462520] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [453.462890] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [453.463293] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [453.463666] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [453.464060] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [453.464431] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [453.464801] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [453.465187] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [453.465561] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [453.465933] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [453.466315] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [453.466687] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [453.467072] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [453.467443] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [453.467814] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [453.468197] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [453.468569] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [453.468939] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [453.469324] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [453.469698] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [453.470078] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [453.470451] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [453.470821] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [453.471208] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [453.471579] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [453.471954] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in has_infoframe (expected no, found yes) <7> [453.472338] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [453.472707] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [453.473095] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [453.473467] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in port_clock (expected 0, found 222750) <7> [453.473841] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [453.474223] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [453.474594] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in avi infoframe <7> [453.474965] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [453.475352] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [453.475725] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [453.475730] i915 0000:00:02.0: colorspace: RGB <7> [453.475733] i915 0000:00:02.0: scan mode: Underscan <7> [453.475737] i915 0000:00:02.0: colorimetry: No Data <7> [453.475740] i915 0000:00:02.0: picture aspect: No Data <7> [453.475744] i915 0000:00:02.0: active aspect: Same as Picture <7> [453.475747] i915 0000:00:02.0: itc: No Data <7> [453.475750] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [453.475754] i915 0000:00:02.0: quantization range: Full <7> [453.475756] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [453.475760] i915 0000:00:02.0: video code: 0 <7> [453.475763] i915 0000:00:02.0: ycc quantization range: Full <7> [453.475766] i915 0000:00:02.0: hdmi content type: Graphics <7> [453.475769] i915 0000:00:02.0: pixel repeat: 0 <7> [453.475772] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [453.475776] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in spd infoframe <7> [453.476158] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [453.476528] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [453.476897] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [453.476900] i915 0000:00:02.0: vendor: Intel <7> [453.476904] i915 0000:00:02.0: product: Integrated gfx <7> [453.476907] i915 0000:00:02.0: source device information: PC General (0x9) <7> [453.476911] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:119:pipe B] fastset requirement not met in hdmi infoframe <7> [453.477296] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [453.477667] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [453.478046] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [453.478050] i915 0000:00:02.0: empty frame <7> [453.478056] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:119:pipe B] fastset requirement not met, forcing full modeset <7> [453.479485] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:119:pipe B] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x2 <7> [453.479956] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:77:plane 1B] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988 <7> [453.480354] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [PLANE:113:cursor B] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32 <7> [453.480725] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [453.481111] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0 <7> [453.481478] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0 <7> [453.481846] i915 0000:00:02.0: [drm:skl_print_plane_changes [i915]] [PLANE:77:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0 <7> [453.482514] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:119:pipe B] min cdclk: 0 kHz -> 192000 kHz <7> [453.482932] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:119:pipe B] using pre-allocated PORT PLL C <7> [453.483352] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:119:pipe B] reserving PORT PLL C <7> [453.483752] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:119:pipe B] enable: yes [modeset] <7> [453.484157] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [453.484531] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 36, dithering: 0 <7> [453.484901] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [453.485287] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [453.485659] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [453.486047] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [453.486416] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [453.486785] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [453.487167] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [453.487172] i915 0000:00:02.0: colorspace: RGB <7> [453.487175] i915 0000:00:02.0: scan mode: Underscan <7> [453.487178] i915 0000:00:02.0: colorimetry: No Data <7> [453.487182] i915 0000:00:02.0: picture aspect: No Data <7> [453.487185] i915 0000:00:02.0: active aspect: Same as Picture <7> [453.487188] i915 0000:00:02.0: itc: No Data <7> [453.487192] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [453.487196] i915 0000:00:02.0: quantization range: Full <7> [453.487199] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [453.487202] i915 0000:00:02.0: video code: 0 <7> [453.487205] i915 0000:00:02.0: ycc quantization range: Full <7> [453.487208] i915 0000:00:02.0: hdmi content type: Graphics <7> [453.487211] i915 0000:00:02.0: pixel repeat: 0 <7> [453.487214] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [453.487218] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [453.487221] i915 0000:00:02.0: vendor: Intel <7> [453.487225] i915 0000:00:02.0: product: Integrated gfx <7> [453.487228] i915 0000:00:02.0: source device information: PC General (0x9) <7> [453.487232] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [453.487236] i915 0000:00:02.0: empty frame <7> [453.487239] 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> [453.487610] 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> [453.487978] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [453.488355] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [453.488728] 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> [453.489119] 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> [453.489489] 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> [453.489859] 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> [453.490239] 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> [453.490612] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [453.490984] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [453.491368] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [453.491741] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000 <7> [453.492122] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0 <7> [453.492494] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [453.492864] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [453.493246] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [453.493620] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6200, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d <7> [453.493991] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [453.494372] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [453.494740] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [453.495124] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [453.495495] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [453.495864] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [453.496245] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [453.496618] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [453.496988] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:77:plane 1B] fb: [FB:180] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [453.497381] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [453.497751] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [453.498134] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:86:plane 2B] fb: [NOFB], visible: no <7> [453.498506] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3B] fb: [NOFB], visible: no <7> [453.498877] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:104:plane 4B] fb: [NOFB], visible: no <7> [453.499265] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:113:cursor B] fb: [NOFB], visible: no <7> [453.501124] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c <7> [453.501920] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:163:DDI B/PHY B] <7> [453.502326] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:173:DDI C/PHY C] <7> [453.503092] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x2, on? 0) for [CRTC:119:pipe B] <7> [453.503512] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C <7> [453.504418] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C <7> [453.504966] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe B <7> [453.522730] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:174:HDMI-A-2][ENCODER:173:DDI C/PHY C] Enable audio codec on [CRTC:119:pipe B], 32 bytes ELD <7> [453.539365] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000) <7> [453.539853] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N <7> [453.541835] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:174:HDMI-A-2] <7> [453.542967] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:119:pipe B] <6> [458.719163] [IGT] kms_flip: finished subtest B-HDMI-A2, FAIL

Detail

Value

Duration

5.50 seconds

Hostname

shard-glk6

Igt-Version

IGT-Version: 2.3-g72b3f732c (x86_64) (Linux: 6.19.0-rc6-CI_DRM_17877-gab42b1c3fe4c+ x86_64)

Out

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

Err

Starting dynamic subtest: B-HDMI-A2
(kms_flip:2543) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2543) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest B-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.694305
last_received_ts = 455.694153
last_seq = 11942
current_ts = 455.710968
current_received_ts = 455.710785
current_seq = 11943
count = 148
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 21us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.710968
last_received_ts = 455.710785
last_seq = 11943
current_ts = 455.727631
current_received_ts = 455.727386
current_seq = 11944
count = 149
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.727631
last_received_ts = 455.727386
last_seq = 11944
current_ts = 455.744293
current_received_ts = 455.744202
current_seq = 11945
count = 150
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 22us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.744293
last_received_ts = 455.744202
last_seq = 11945
current_ts = 455.760956
current_received_ts = 455.760925
current_seq = 11946
count = 151
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 22us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.760956
last_received_ts = 455.760925
last_seq = 11946
current_ts = 455.777618
current_received_ts = 455.777466
current_seq = 11947
count = 152
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.777618
last_received_ts = 455.777466
last_seq = 11947
current_ts = 455.794281
current_received_ts = 455.794159
current_seq = 11948
count = 153
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.794281
last_received_ts = 455.794159
last_seq = 11948
current_ts = 455.810974
current_received_ts = 455.810791
current_seq = 11949
count = 154
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 22us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.810974
last_received_ts = 455.810791
last_seq = 11949
current_ts = 455.827637
current_received_ts = 455.827545
current_seq = 11950
count = 155
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.827637
last_received_ts = 455.827545
last_seq = 11950
current_ts = 455.844299
current_received_ts = 455.843811
current_seq = 11951
count = 156
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.844299
last_received_ts = 455.843811
last_seq = 11951
current_ts = 455.860962
current_received_ts = 455.860779
current_seq = 11952
count = 157
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 21us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.860962
last_received_ts = 455.860779
last_seq = 11952
current_ts = 455.877625
current_received_ts = 455.877472
current_seq = 11953
count = 158
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.877625
last_received_ts = 455.877472
last_seq = 11953
current_ts = 455.894287
current_received_ts = 455.894165
current_seq = 11954
count = 159
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.894287
last_received_ts = 455.894165
last_seq = 11954
current_ts = 455.910950
current_received_ts = 455.910797
current_seq = 11955
count = 160
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 21us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.910950
last_received_ts = 455.910797
last_seq = 11955
current_ts = 455.927612
current_received_ts = 455.927460
current_seq = 11956
count = 161
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.927612
last_received_ts = 455.927460
last_seq = 11956
current_ts = 455.944275
current_received_ts = 455.944183
current_seq = 11957
count = 162
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.944275
last_received_ts = 455.944183
last_seq = 11957
current_ts = 455.960968
current_received_ts = 455.960785
current_seq = 11958
count = 163
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 21us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.960968
last_received_ts = 455.960785
last_seq = 11958
current_ts = 455.977631
current_received_ts = 455.977539
current_seq = 11959
count = 164
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.977631
last_received_ts = 455.977539
last_seq = 11959
current_ts = 455.994293
current_received_ts = 455.994202
current_seq = 11960
count = 165
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 455.994293
last_received_ts = 455.994202
last_seq = 11960
current_ts = 456.010956
current_received_ts = 456.010773
current_seq = 11961
count = 166
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 21us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.010956
last_received_ts = 456.010773
last_seq = 11961
current_ts = 456.027618
current_received_ts = 456.027466
current_seq = 11962
count = 167
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.027618
last_received_ts = 456.027466
last_seq = 11962
current_ts = 456.044312
current_received_ts = 456.044189
current_seq = 11963
count = 168
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.044312
last_received_ts = 456.044189
last_seq = 11963
current_ts = 456.060974
current_received_ts = 456.060852
current_seq = 11964
count = 169
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.060974
last_received_ts = 456.060852
last_seq = 11964
current_ts = 456.077637
current_received_ts = 456.077545
current_seq = 11965
count = 170
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.077637
last_received_ts = 456.077545
last_seq = 11965
current_ts = 456.094299
current_received_ts = 456.094208
current_seq = 11966
count = 171
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.094299
last_received_ts = 456.094208
last_seq = 11966
current_ts = 456.110962
current_received_ts = 456.110779
current_seq = 11967
count = 172
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 20us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.110962
last_received_ts = 456.110779
last_seq = 11967
current_ts = 456.127625
current_received_ts = 456.127472
current_seq = 11968
count = 173
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.127625
last_received_ts = 456.127472
last_seq = 11968
current_ts = 456.144287
current_received_ts = 456.144165
current_seq = 11969
count = 174
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.144287
last_received_ts = 456.144165
last_seq = 11969
current_ts = 456.160980
current_received_ts = 456.160828
current_seq = 11970
count = 175
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.160980
last_received_ts = 456.160828
last_seq = 11970
current_ts = 456.177643
current_received_ts = 456.177521
current_seq = 11971
count = 176
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.177643
last_received_ts = 456.177521
last_seq = 11971
current_ts = 456.194305
current_received_ts = 456.194122
current_seq = 11972
count = 177
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.194305
last_received_ts = 456.194122
last_seq = 11972
current_ts = 456.210968
current_received_ts = 456.210815
current_seq = 11973
count = 178
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 18us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.210968
last_received_ts = 456.210815
last_seq = 11973
current_ts = 456.227631
current_received_ts = 456.227356
current_seq = 11974
count = 179
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.227631
last_received_ts = 456.227356
last_seq = 11974
current_ts = 456.244293
current_received_ts = 456.244171
current_seq = 11975
count = 180
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.244293
last_received_ts = 456.244171
last_seq = 11975
current_ts = 456.260956
current_received_ts = 456.260864
current_seq = 11976
count = 181
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.260956
last_received_ts = 456.260864
last_seq = 11976
current_ts = 456.277618
current_received_ts = 456.277466
current_seq = 11977
count = 182
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.277618
last_received_ts = 456.277466
last_seq = 11977
current_ts = 456.294312
current_received_ts = 456.294403
current_seq = 11978
count = 183
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 23us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.294312
last_received_ts = 456.294403
last_seq = 11978
current_ts = 456.310974
current_received_ts = 456.310883
current_seq = 11979
count = 184
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.310974
last_received_ts = 456.310883
last_seq = 11979
current_ts = 456.327637
current_received_ts = 456.327393
current_seq = 11980
count = 185
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.327637
last_received_ts = 456.327393
last_seq = 11980
current_ts = 456.344299
current_received_ts = 456.344116
current_seq = 11981
count = 186
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.344299
last_received_ts = 456.344116
last_seq = 11981
current_ts = 456.360962
current_received_ts = 456.360779
current_seq = 11982
count = 187
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 23us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.360962
last_received_ts = 456.360779
last_seq = 11982
current_ts = 456.377625
current_received_ts = 456.377533
current_seq = 11983
count = 188
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.377625
last_received_ts = 456.377533
last_seq = 11983
current_ts = 456.394287
current_received_ts = 456.394104
current_seq = 11984
count = 189
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.394287
last_received_ts = 456.394104
last_seq = 11984
current_ts = 456.410950
current_received_ts = 456.410858
current_seq = 11985
count = 190
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.410950
last_received_ts = 456.410858
last_seq = 11985
current_ts = 456.427643
current_received_ts = 456.427521
current_seq = 11986
count = 191
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.427643
last_received_ts = 456.427521
last_seq = 11986
current_ts = 456.444305
current_received_ts = 456.444092
current_seq = 11987
count = 192
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.444305
last_received_ts = 456.444092
last_seq = 11987
current_ts = 456.460968
current_received_ts = 456.460876
current_seq = 11988
count = 193
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.460968
last_received_ts = 456.460876
last_seq = 11988
current_ts = 456.477631
current_received_ts = 456.477539
current_seq = 11989
count = 194
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.477631
last_received_ts = 456.477539
last_seq = 11989
current_ts = 456.494293
current_received_ts = 456.494080
current_seq = 11990
count = 195
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.494293
last_received_ts = 456.494080
last_seq = 11990
current_ts = 456.510956
current_received_ts = 456.510864
current_seq = 11991
count = 196
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.510956
last_received_ts = 456.510864
last_seq = 11991
current_ts = 456.527649
current_received_ts = 456.527496
current_seq = 11992
count = 197
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.527649
last_received_ts = 456.527496
last_seq = 11992
current_ts = 456.544312
current_received_ts = 456.544098
current_seq = 11993
count = 198
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.544312
last_received_ts = 456.544098
last_seq = 11993
current_ts = 456.560974
current_received_ts = 456.560852
current_seq = 11994
count = 199
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.560974
last_received_ts = 456.560852
last_seq = 11994
current_ts = 456.577637
current_received_ts = 456.577545
current_seq = 11995
count = 200
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.577637
last_received_ts = 456.577545
last_seq = 11995
current_ts = 456.594299
current_received_ts = 456.594055
current_seq = 11996
count = 201
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.594299
last_received_ts = 456.594055
last_seq = 11996
current_ts = 456.610962
current_received_ts = 456.610809
current_seq = 11997
count = 202
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 22us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.610962
last_received_ts = 456.610809
last_seq = 11997
current_ts = 456.627655
current_received_ts = 456.627350
current_seq = 11998
count = 203
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.627655
last_received_ts = 456.627350
last_seq = 11998
current_ts = 456.644318
current_received_ts = 456.644104
current_seq = 11999
count = 204
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.644318
last_received_ts = 456.644104
last_seq = 11999
current_ts = 456.660980
current_received_ts = 456.660889
current_seq = 12000
count = 205
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.660980
last_received_ts = 456.660889
last_seq = 12000
current_ts = 456.677643
current_received_ts = 456.677490
current_seq = 12001
count = 206
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.677643
last_received_ts = 456.677490
last_seq = 12001
current_ts = 456.694305
current_received_ts = 456.694092
current_seq = 12002
count = 207
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.694305
last_received_ts = 456.694092
last_seq = 12002
current_ts = 456.710968
current_received_ts = 456.710815
current_seq = 12003
count = 208
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.710968
last_received_ts = 456.710815
last_seq = 12003
current_ts = 456.727631
current_received_ts = 456.727417
current_seq = 12004
count = 209
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.727631
last_received_ts = 456.727417
last_seq = 12004
current_ts = 456.744293
current_received_ts = 456.744080
current_seq = 12005
count = 210
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.744293
last_received_ts = 456.744080
last_seq = 12005
current_ts = 456.760986
current_received_ts = 456.760864
current_seq = 12006
count = 211
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.760986
last_received_ts = 456.760864
last_seq = 12006
current_ts = 456.777649
current_received_ts = 456.777435
current_seq = 12007
count = 212
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.777649
last_received_ts = 456.777435
last_seq = 12007
current_ts = 456.794312
current_received_ts = 456.794220
current_seq = 12008
count = 213
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.794312
last_received_ts = 456.794220
last_seq = 12008
current_ts = 456.810974
current_received_ts = 456.810822
current_seq = 12009
count = 214
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 20us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.810974
last_received_ts = 456.810822
last_seq = 12009
current_ts = 456.827637
current_received_ts = 456.827484
current_seq = 12010
count = 215
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.827637
last_received_ts = 456.827484
last_seq = 12010
current_ts = 456.844299
current_received_ts = 456.844177
current_seq = 12011
count = 216
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.844299
last_received_ts = 456.844177
last_seq = 12011
current_ts = 456.860962
current_received_ts = 456.860809
current_seq = 12012
count = 217
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 22us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.860962
last_received_ts = 456.860809
last_seq = 12012
current_ts = 456.877655
current_received_ts = 456.877533
current_seq = 12013
count = 218
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.877655
last_received_ts = 456.877533
last_seq = 12013
current_ts = 456.894318
current_received_ts = 456.894104
current_seq = 12014
count = 219
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.894318
last_received_ts = 456.894104
last_seq = 12014
current_ts = 456.910980
current_received_ts = 456.910858
current_seq = 12015
count = 220
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.910980
last_received_ts = 456.910858
last_seq = 12015
current_ts = 456.927643
current_received_ts = 456.927490
current_seq = 12016
count = 221
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.927643
last_received_ts = 456.927490
last_seq = 12016
current_ts = 456.944305
current_received_ts = 456.944183
current_seq = 12017
count = 222
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 16us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.944305
last_received_ts = 456.944183
last_seq = 12017
current_ts = 456.960968
current_received_ts = 456.960876
current_seq = 12018
count = 223
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.960968
last_received_ts = 456.960876
last_seq = 12018
current_ts = 456.977631
current_received_ts = 456.977539
current_seq = 12019
count = 224
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.977631
last_received_ts = 456.977539
last_seq = 12019
current_ts = 456.994293
current_received_ts = 456.994110
current_seq = 12020
count = 225
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 456.994293
last_received_ts = 456.994110
last_seq = 12020
current_ts = 457.010986
current_received_ts = 457.010803
current_seq = 12021
count = 226
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 22us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.010986
last_received_ts = 457.010803
last_seq = 12021
current_ts = 457.027649
current_received_ts = 457.027557
current_seq = 12022
count = 227
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.027649
last_received_ts = 457.027557
last_seq = 12022
current_ts = 457.044312
current_received_ts = 457.044098
current_seq = 12023
count = 228
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.044312
last_received_ts = 457.044098
last_seq = 12023
current_ts = 457.060974
current_received_ts = 457.060791
current_seq = 12024
count = 229
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.060974
last_received_ts = 457.060791
last_seq = 12024
current_ts = 457.077637
current_received_ts = 457.077545
current_seq = 12025
count = 230
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.077637
last_received_ts = 457.077545
last_seq = 12025
current_ts = 457.094299
current_received_ts = 457.094116
current_seq = 12026
count = 231
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.094299
last_received_ts = 457.094116
last_seq = 12026
current_ts = 457.110992
current_received_ts = 457.110901
current_seq = 12027
count = 232
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.110992
last_received_ts = 457.110901
last_seq = 12027
current_ts = 457.127655
current_received_ts = 457.127472
current_seq = 12028
count = 233
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.127655
last_received_ts = 457.127472
last_seq = 12028
current_ts = 457.144318
current_received_ts = 457.144165
current_seq = 12029
count = 234
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 18us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.144318
last_received_ts = 457.144165
last_seq = 12029
current_ts = 457.160980
current_received_ts = 457.160858
current_seq = 12030
count = 235
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.160980
last_received_ts = 457.160858
last_seq = 12030
current_ts = 457.177643
current_received_ts = 457.177521
current_seq = 12031
count = 236
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.177643
last_received_ts = 457.177521
last_seq = 12031
current_ts = 457.194305
current_received_ts = 457.194122
current_seq = 12032
count = 237
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.194305
last_received_ts = 457.194122
last_seq = 12032
current_ts = 457.210999
current_received_ts = 457.210815
current_seq = 12033
count = 238
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 20us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.210999
last_received_ts = 457.210815
last_seq = 12033
current_ts = 457.227661
current_received_ts = 457.227814
current_seq = 12034
count = 239
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 21us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.227661
last_received_ts = 457.227814
last_seq = 12034
current_ts = 457.244324
current_received_ts = 457.244202
current_seq = 12035
count = 240
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.244324
last_received_ts = 457.244202
last_seq = 12035
current_ts = 457.260986
current_received_ts = 457.260864
current_seq = 12036
count = 241
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.260986
last_received_ts = 457.260864
last_seq = 12036
current_ts = 457.277649
current_received_ts = 457.277557
current_seq = 12037
count = 242
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.277649
last_received_ts = 457.277557
last_seq = 12037
current_ts = 457.294312
current_received_ts = 457.294189
current_seq = 12038
count = 243
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.294312
last_received_ts = 457.294189
last_seq = 12038
current_ts = 457.310974
current_received_ts = 457.310791
current_seq = 12039
count = 244
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 21us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.310974
last_received_ts = 457.310791
last_seq = 12039
current_ts = 457.327637
current_received_ts = 457.327423
current_seq = 12040
count = 245
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.327637
last_received_ts = 457.327423
last_seq = 12040
current_ts = 457.344330
current_received_ts = 457.344208
current_seq = 12041
count = 246
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.344330
last_received_ts = 457.344208
last_seq = 12041
current_ts = 457.360992
current_received_ts = 457.360870
current_seq = 12042
count = 247
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.360992
last_received_ts = 457.360870
last_seq = 12042
current_ts = 457.377655
current_received_ts = 457.377563
current_seq = 12043
count = 248
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.377655
last_received_ts = 457.377563
last_seq = 12043
current_ts = 457.394318
current_received_ts = 457.394226
current_seq = 12044
count = 249
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.394318
last_received_ts = 457.394226
last_seq = 12044
current_ts = 457.410980
current_received_ts = 457.410889
current_seq = 12045
count = 250
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.410980
last_received_ts = 457.410889
last_seq = 12045
current_ts = 457.427643
current_received_ts = 457.427490
current_seq = 12046
count = 251
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.427643
last_received_ts = 457.427490
last_seq = 12046
current_ts = 457.444336
current_received_ts = 457.444153
current_seq = 12047
count = 252
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.444336
last_received_ts = 457.444153
last_seq = 12047
current_ts = 457.460968
current_received_ts = 457.460876
current_seq = 12048
count = 253
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.460968
last_received_ts = 457.460876
last_seq = 12048
current_ts = 457.477661
current_received_ts = 457.477478
current_seq = 12049
count = 254
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 21us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.477661
last_received_ts = 457.477478
last_seq = 12049
current_ts = 457.494324
current_received_ts = 457.494232
current_seq = 12050
count = 255
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.494324
last_received_ts = 457.494232
last_seq = 12050
current_ts = 457.510986
current_received_ts = 457.510834
current_seq = 12051
count = 256
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 20us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.510986
last_received_ts = 457.510834
last_seq = 12051
current_ts = 457.527649
current_received_ts = 457.527435
current_seq = 12052
count = 257
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 27us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.527649
last_received_ts = 457.527435
last_seq = 12052
current_ts = 457.544342
current_received_ts = 457.544128
current_seq = 12053
count = 258
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 17us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.544342
last_received_ts = 457.544128
last_seq = 12053
current_ts = 457.561005
current_received_ts = 457.560852
current_seq = 12054
count = 259
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.561005
last_received_ts = 457.560852
last_seq = 12054
current_ts = 457.577667
current_received_ts = 457.577545
current_seq = 12055
count = 260
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 25us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.577667
last_received_ts = 457.577545
last_seq = 12055
current_ts = 457.594330
current_received_ts = 457.594177
current_seq = 12056
count = 261
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.594330
last_received_ts = 457.594177
last_seq = 12056
current_ts = 457.610992
current_received_ts = 457.610901
current_seq = 12057
count = 262
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.610992
last_received_ts = 457.610901
last_seq = 12057
current_ts = 457.627655
current_received_ts = 457.627563
current_seq = 12058
count = 263
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.627655
last_received_ts = 457.627563
last_seq = 12058
current_ts = 457.644348
current_received_ts = 457.644226
current_seq = 12059
count = 264
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.644348
last_received_ts = 457.644226
last_seq = 12059
current_ts = 457.661011
current_received_ts = 457.660828
current_seq = 12060
count = 265
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 20us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.661011
last_received_ts = 457.660828
last_seq = 12060
current_ts = 457.677673
current_received_ts = 457.677551
current_seq = 12061
count = 266
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.677673
last_received_ts = 457.677551
last_seq = 12061
current_ts = 457.694336
current_received_ts = 457.694153
current_seq = 12062
count = 267
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 24us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.694336
last_received_ts = 457.694153
last_seq = 12062
current_ts = 457.710999
current_received_ts = 457.710876
current_seq = 12063
count = 268
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 26us
(kms_flip:2543) DEBUG: name = flip
last_ts = 457.710999
last_received_ts = 457.710876
last_seq = 12063
current_ts = 457.727661
current_received_ts = 457.727509
current_seq = 12064
count = 269
seq_step = 1
(kms_flip:2543) DEBUG: Vblank took 1015us
(kms_flip:2543) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2543) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2543) igt_core-INFO: Stack trace:
(kms_flip:2543) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2543) igt_core-INFO:   #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
(kms_flip:2543) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:2543) igt_core-INFO:   #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
(kms_flip:2543) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:2543) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2543) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2543) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-HDMI-A2: FAIL (5.505s)

Dmesg

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

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

<7> [453.214498] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:184]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [453.487239] 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> [453.487610] 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> [453.487978] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2

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

<7> [453.488728] 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> [453.489119] 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> [453.489489] 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> [453.489859] 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> [453.490239] 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> [453.490612] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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