igt@kms_flip@flip-vs-expired-vblank-interruptible@c-hdmi-a1 on shard-rkl@IGTPW

Detail	Value
Duration	1.99 seconds
Hostname	shard-rkl-5
Igt-Version	IGT-Version: 2.4-ga22943872 (x86_64) (Linux: 7.1.0-rc2-CI_DRM_18452-g680a4832a818+ x86_64)
Out	Starting dynamic subtest: C-HDMI-A1 1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest C-HDMI-A1: FAIL (1.992s) Subtest flip-vs-expired-vblank-interruptible: FAIL (22.381s) Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../lib/igt_kms.c:2352 kmstest_set_connector_dpms() #2 ../lib/igt_core.c:2961 igt_atexit_handler() #3 [erand48_r+0x1d6] #4 [exit+0x1e] #5 ../lib/igt_core.c:2416 igt_exit() #6 [main+0x3f] #7 [__libc_init_first+0x8a] #8 [__libc_start_main+0x8b] #9 [_start+0x25]
Err	Starting dynamic subtest: C-HDMI-A1 (kms_flip:2490) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2490) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2490) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest C-HDMI-A1 failed. ** DEBUG (kms_flip:2490) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000001, size=0) (kms_flip:2490) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2490) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2490) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=7680) (kms_flip:2490) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:2490) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000001, size=0) (kms_flip:2490) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2490) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2490) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680) (kms_flip:2490) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:2490) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2490) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2490) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS (kms_flip:2490) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2490) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2490) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS (kms_flip:2490) igt_kms-INFO: 1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 (kms_flip:2490) DEBUG: No stale events found (kms_flip:2490) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0 (kms_flip:2490) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0 (kms_flip:2490) DEBUG: name = flip last_ts = 0.000000 last_received_ts = 0.000000 last_seq = 0 current_ts = 273.666046 current_received_ts = 273.665405 current_seq = 207 count = 0 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 27us (kms_flip:2490) DEBUG: name = flip last_ts = 273.666046 last_received_ts = 273.665405 last_seq = 207 current_ts = 273.685028 current_received_ts = 273.684357 current_seq = 208 count = 1 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 273.685028 last_received_ts = 273.684357 last_seq = 208 current_ts = 273.704010 current_received_ts = 273.703461 current_seq = 209 count = 2 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 273.704010 last_received_ts = 273.703461 last_seq = 209 current_ts = 273.722961 current_received_ts = 273.722351 current_seq = 210 count = 3 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 29us (kms_flip:2490) DEBUG: name = flip last_ts = 273.722961 last_received_ts = 273.722351 last_seq = 210 current_ts = 273.741943 current_received_ts = 273.741333 current_seq = 211 count = 4 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 27us (kms_flip:2490) DEBUG: name = flip last_ts = 273.741943 last_received_ts = 273.741333 last_seq = 211 current_ts = 273.760925 current_received_ts = 273.760345 current_seq = 212 count = 5 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 29us (kms_flip:2490) DEBUG: name = flip last_ts = 273.760925 last_received_ts = 273.760345 last_seq = 212 current_ts = 273.779877 current_received_ts = 273.779266 current_seq = 213 count = 6 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 29us (kms_flip:2490) DEBUG: name = flip last_ts = 273.779877 last_received_ts = 273.779266 last_seq = 213 current_ts = 273.798859 current_received_ts = 273.798248 current_seq = 214 count = 7 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 273.798859 last_received_ts = 273.798248 last_seq = 214 current_ts = 273.817841 current_received_ts = 273.817200 current_seq = 215 count = 8 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 273.817841 last_received_ts = 273.817200 last_seq = 215 current_ts = 273.836823 current_received_ts = 273.836182 current_seq = 216 count = 9 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 273.836823 last_received_ts = 273.836182 last_seq = 216 current_ts = 273.855804 current_received_ts = 273.855225 current_seq = 217 count = 10 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 273.855804 last_received_ts = 273.855225 last_seq = 217 current_ts = 273.874756 current_received_ts = 273.874237 current_seq = 218 count = 11 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 273.874756 last_received_ts = 273.874237 last_seq = 218 current_ts = 273.893738 current_received_ts = 273.893219 current_seq = 219 count = 12 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 273.893738 last_received_ts = 273.893219 last_seq = 219 current_ts = 273.912720 current_received_ts = 273.912079 current_seq = 220 count = 13 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 26us (kms_flip:2490) DEBUG: name = flip last_ts = 273.912720 last_received_ts = 273.912079 last_seq = 220 current_ts = 273.931671 current_received_ts = 273.931122 current_seq = 221 count = 14 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 26us (kms_flip:2490) DEBUG: name = flip last_ts = 273.931671 last_received_ts = 273.931122 last_seq = 221 current_ts = 273.950653 current_received_ts = 273.950073 current_seq = 222 count = 15 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 30us (kms_flip:2490) DEBUG: name = flip last_ts = 273.950653 last_received_ts = 273.950073 last_seq = 222 current_ts = 273.969635 current_received_ts = 273.969055 current_seq = 223 count = 16 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 273.969635 last_received_ts = 273.969055 last_seq = 223 current_ts = 273.988617 current_received_ts = 273.987976 current_seq = 224 count = 17 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 273.988617 last_received_ts = 273.987976 last_seq = 224 current_ts = 274.007599 current_received_ts = 274.007050 current_seq = 225 count = 18 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.007599 last_received_ts = 274.007050 last_seq = 225 current_ts = 274.026550 current_received_ts = 274.025970 current_seq = 226 count = 19 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 59us (kms_flip:2490) DEBUG: name = flip last_ts = 274.026550 last_received_ts = 274.025970 last_seq = 226 current_ts = 274.045532 current_received_ts = 274.044922 current_seq = 227 count = 20 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.045532 last_received_ts = 274.044922 last_seq = 227 current_ts = 274.064484 current_received_ts = 274.063934 current_seq = 228 count = 21 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.064484 last_received_ts = 274.063934 last_seq = 228 current_ts = 274.083496 current_received_ts = 274.082886 current_seq = 229 count = 22 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.083496 last_received_ts = 274.082886 last_seq = 229 current_ts = 274.102448 current_received_ts = 274.101837 current_seq = 230 count = 23 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.102448 last_received_ts = 274.101837 last_seq = 230 current_ts = 274.121429 current_received_ts = 274.120819 current_seq = 231 count = 24 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 64us (kms_flip:2490) DEBUG: name = flip last_ts = 274.121429 last_received_ts = 274.120819 last_seq = 231 current_ts = 274.140381 current_received_ts = 274.139771 current_seq = 232 count = 25 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.140381 last_received_ts = 274.139771 last_seq = 232 current_ts = 274.159393 current_received_ts = 274.158783 current_seq = 233 count = 26 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.159393 last_received_ts = 274.158783 last_seq = 233 current_ts = 274.178345 current_received_ts = 274.177734 current_seq = 234 count = 27 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 27us (kms_flip:2490) DEBUG: name = flip last_ts = 274.178345 last_received_ts = 274.177734 last_seq = 234 current_ts = 274.197327 current_received_ts = 274.196686 current_seq = 235 count = 28 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.197327 last_received_ts = 274.196686 last_seq = 235 current_ts = 274.216278 current_received_ts = 274.215668 current_seq = 236 count = 29 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.216278 last_received_ts = 274.215668 last_seq = 236 current_ts = 274.235260 current_received_ts = 274.234711 current_seq = 237 count = 30 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.235260 last_received_ts = 274.234711 last_seq = 237 current_ts = 274.254242 current_received_ts = 274.253693 current_seq = 238 count = 31 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.254242 last_received_ts = 274.253693 last_seq = 238 current_ts = 274.273224 current_received_ts = 274.272614 current_seq = 239 count = 32 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.273224 last_received_ts = 274.272614 last_seq = 239 current_ts = 274.292206 current_received_ts = 274.291595 current_seq = 240 count = 33 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.292206 last_received_ts = 274.291595 last_seq = 240 current_ts = 274.311157 current_received_ts = 274.310547 current_seq = 241 count = 34 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.311157 last_received_ts = 274.310547 last_seq = 241 current_ts = 274.330139 current_received_ts = 274.329498 current_seq = 242 count = 35 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.330139 last_received_ts = 274.329498 last_seq = 242 current_ts = 274.349121 current_received_ts = 274.348511 current_seq = 243 count = 36 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 28us (kms_flip:2490) DEBUG: name = flip last_ts = 274.349121 last_received_ts = 274.348511 last_seq = 243 current_ts = 274.368103 current_received_ts = 274.367493 current_seq = 244 count = 37 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.368103 last_received_ts = 274.367493 last_seq = 244 current_ts = 274.387054 current_received_ts = 274.386444 current_seq = 245 count = 38 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.387054 last_received_ts = 274.386444 last_seq = 245 current_ts = 274.406036 current_received_ts = 274.405396 current_seq = 246 count = 39 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.406036 last_received_ts = 274.405396 last_seq = 246 current_ts = 274.425018 current_received_ts = 274.424377 current_seq = 247 count = 40 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 28us (kms_flip:2490) DEBUG: name = flip last_ts = 274.425018 last_received_ts = 274.424377 last_seq = 247 current_ts = 274.443970 current_received_ts = 274.443481 current_seq = 248 count = 41 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.443970 last_received_ts = 274.443481 last_seq = 248 current_ts = 274.462952 current_received_ts = 274.462372 current_seq = 249 count = 42 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.462952 last_received_ts = 274.462372 last_seq = 249 current_ts = 274.481934 current_received_ts = 274.481354 current_seq = 250 count = 43 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 25us (kms_flip:2490) DEBUG: name = flip last_ts = 274.481934 last_received_ts = 274.481354 last_seq = 250 current_ts = 274.500916 current_received_ts = 274.500305 current_seq = 251 count = 44 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 30us (kms_flip:2490) DEBUG: name = flip last_ts = 274.500916 last_received_ts = 274.500305 last_seq = 251 current_ts = 274.519867 current_received_ts = 274.519287 current_seq = 252 count = 45 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.519867 last_received_ts = 274.519287 last_seq = 252 current_ts = 274.538849 current_received_ts = 274.538208 current_seq = 253 count = 46 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.538849 last_received_ts = 274.538208 last_seq = 253 current_ts = 274.557831 current_received_ts = 274.557190 current_seq = 254 count = 47 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.557831 last_received_ts = 274.557190 last_seq = 254 current_ts = 274.576813 current_received_ts = 274.576202 current_seq = 255 count = 48 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.576813 last_received_ts = 274.576202 last_seq = 255 current_ts = 274.595764 current_received_ts = 274.595215 current_seq = 256 count = 49 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.595764 last_received_ts = 274.595215 last_seq = 256 current_ts = 274.614746 current_received_ts = 274.614197 current_seq = 257 count = 50 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.614746 last_received_ts = 274.614197 last_seq = 257 current_ts = 274.633728 current_received_ts = 274.633118 current_seq = 258 count = 51 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.633728 last_received_ts = 274.633118 last_seq = 258 current_ts = 274.652679 current_received_ts = 274.652100 current_seq = 259 count = 52 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.652679 last_received_ts = 274.652100 last_seq = 259 current_ts = 274.671692 current_received_ts = 274.671082 current_seq = 260 count = 53 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 34us (kms_flip:2490) DEBUG: name = flip last_ts = 274.671692 last_received_ts = 274.671082 last_seq = 260 current_ts = 274.690643 current_received_ts = 274.690002 current_seq = 261 count = 54 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 43us (kms_flip:2490) DEBUG: name = flip last_ts = 274.690643 last_received_ts = 274.690002 last_seq = 261 current_ts = 274.709625 current_received_ts = 274.709045 current_seq = 262 count = 55 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 64us (kms_flip:2490) DEBUG: name = flip last_ts = 274.709625 last_received_ts = 274.709045 last_seq = 262 current_ts = 274.728607 current_received_ts = 274.728027 current_seq = 263 count = 56 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.728607 last_received_ts = 274.728027 last_seq = 263 current_ts = 274.747589 current_received_ts = 274.746979 current_seq = 264 count = 57 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.747589 last_received_ts = 274.746979 last_seq = 264 current_ts = 274.766541 current_received_ts = 274.765961 current_seq = 265 count = 58 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 65us (kms_flip:2490) DEBUG: name = flip last_ts = 274.766541 last_received_ts = 274.765961 last_seq = 265 current_ts = 274.785522 current_received_ts = 274.784912 current_seq = 266 count = 59 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.785522 last_received_ts = 274.784912 last_seq = 266 current_ts = 274.804504 current_received_ts = 274.803864 current_seq = 267 count = 60 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 30us (kms_flip:2490) DEBUG: name = flip last_ts = 274.804504 last_received_ts = 274.803864 last_seq = 267 current_ts = 274.823456 current_received_ts = 274.822815 current_seq = 268 count = 61 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.823456 last_received_ts = 274.822815 last_seq = 268 current_ts = 274.842438 current_received_ts = 274.841858 current_seq = 269 count = 62 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.842438 last_received_ts = 274.841858 last_seq = 269 current_ts = 274.861420 current_received_ts = 274.860809 current_seq = 270 count = 63 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.861420 last_received_ts = 274.860809 last_seq = 270 current_ts = 274.880402 current_received_ts = 274.879791 current_seq = 271 count = 64 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.880402 last_received_ts = 274.879791 last_seq = 271 current_ts = 274.899353 current_received_ts = 274.898834 current_seq = 272 count = 65 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 26us (kms_flip:2490) DEBUG: name = flip last_ts = 274.899353 last_received_ts = 274.898834 last_seq = 272 current_ts = 274.918335 current_received_ts = 274.917725 current_seq = 273 count = 66 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.918335 last_received_ts = 274.917725 last_seq = 273 current_ts = 274.937317 current_received_ts = 274.936676 current_seq = 274 count = 67 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 274.937317 last_received_ts = 274.936676 last_seq = 274 current_ts = 274.956299 current_received_ts = 274.955688 current_seq = 275 count = 68 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 274.956299 last_received_ts = 274.955688 last_seq = 275 current_ts = 274.975250 current_received_ts = 274.974670 current_seq = 276 count = 69 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 30us (kms_flip:2490) DEBUG: name = flip last_ts = 274.975250 last_received_ts = 274.974670 last_seq = 276 current_ts = 274.994232 current_received_ts = 274.993622 current_seq = 277 count = 70 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 274.994232 last_received_ts = 274.993622 last_seq = 277 current_ts = 275.013184 current_received_ts = 275.012604 current_seq = 278 count = 71 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 30us (kms_flip:2490) DEBUG: name = flip last_ts = 275.013184 last_received_ts = 275.012604 last_seq = 278 current_ts = 275.032196 current_received_ts = 275.031586 current_seq = 279 count = 72 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 26us (kms_flip:2490) DEBUG: name = flip last_ts = 275.032196 last_received_ts = 275.031586 last_seq = 279 current_ts = 275.051147 current_received_ts = 275.050568 current_seq = 280 count = 73 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 275.051147 last_received_ts = 275.050568 last_seq = 280 current_ts = 275.070129 current_received_ts = 275.069489 current_seq = 281 count = 74 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 275.070129 last_received_ts = 275.069489 last_seq = 281 current_ts = 275.089111 current_received_ts = 275.088531 current_seq = 282 count = 75 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 55us (kms_flip:2490) DEBUG: name = flip last_ts = 275.089111 last_received_ts = 275.088531 last_seq = 282 current_ts = 275.108063 current_received_ts = 275.107483 current_seq = 283 count = 76 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 275.108063 last_received_ts = 275.107483 last_seq = 283 current_ts = 275.127045 current_received_ts = 275.126434 current_seq = 284 count = 77 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 275.127045 last_received_ts = 275.126434 last_seq = 284 current_ts = 275.146027 current_received_ts = 275.145416 current_seq = 285 count = 78 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 275.146027 last_received_ts = 275.145416 last_seq = 285 current_ts = 275.165009 current_received_ts = 275.164520 current_seq = 286 count = 79 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 275.165009 last_received_ts = 275.164520 last_seq = 286 current_ts = 275.183960 current_received_ts = 275.183350 current_seq = 287 count = 80 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 275.183960 last_received_ts = 275.183350 last_seq = 287 current_ts = 275.202942 current_received_ts = 275.202362 current_seq = 288 count = 81 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 275.202942 last_received_ts = 275.202362 last_seq = 288 current_ts = 275.221924 current_received_ts = 275.221344 current_seq = 289 count = 82 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 26us (kms_flip:2490) DEBUG: name = flip last_ts = 275.221924 last_received_ts = 275.221344 last_seq = 289 current_ts = 275.240906 current_received_ts = 275.240326 current_seq = 290 count = 83 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 30us (kms_flip:2490) DEBUG: name = flip last_ts = 275.240906 last_received_ts = 275.240326 last_seq = 290 current_ts = 275.259888 current_received_ts = 275.259216 current_seq = 291 count = 84 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 275.259888 last_received_ts = 275.259216 last_seq = 291 current_ts = 275.278839 current_received_ts = 275.278198 current_seq = 292 count = 85 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 275.278839 last_received_ts = 275.278198 last_seq = 292 current_ts = 275.297821 current_received_ts = 275.297241 current_seq = 293 count = 86 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 31us (kms_flip:2490) DEBUG: name = flip last_ts = 275.297821 last_received_ts = 275.297241 last_seq = 293 current_ts = 275.316803 current_received_ts = 275.316254 current_seq = 294 count = 87 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 275.316803 last_received_ts = 275.316254 last_seq = 294 current_ts = 275.335754 current_received_ts = 275.335205 current_seq = 295 count = 88 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 275.335754 last_received_ts = 275.335205 last_seq = 295 current_ts = 275.354736 current_received_ts = 275.354095 current_seq = 296 count = 89 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 275.354736 last_received_ts = 275.354095 last_seq = 296 current_ts = 275.373718 current_received_ts = 275.373108 current_seq = 297 count = 90 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 25us (kms_flip:2490) DEBUG: name = flip last_ts = 275.373718 last_received_ts = 275.373108 last_seq = 297 current_ts = 275.392700 current_received_ts = 275.392090 current_seq = 298 count = 91 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 275.392700 last_received_ts = 275.392090 last_seq = 298 current_ts = 275.411652 current_received_ts = 275.411102 current_seq = 299 count = 92 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 32us (kms_flip:2490) DEBUG: name = flip last_ts = 275.411652 last_received_ts = 275.411102 last_seq = 299 current_ts = 275.430634 current_received_ts = 275.429993 current_seq = 300 count = 93 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 33us (kms_flip:2490) DEBUG: name = flip last_ts = 275.430634 last_received_ts = 275.429993 last_seq = 300 current_ts = 275.449615 current_received_ts = 275.449097 current_seq = 301 count = 94 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 28us (kms_flip:2490) DEBUG: name = flip last_ts = 275.449615 last_received_ts = 275.449097 last_seq = 301 current_ts = 275.468567 current_received_ts = 275.467957 current_seq = 302 count = 95 seq_step = 1 (kms_flip:2490) DEBUG: Vblank took 837us (kms_flip:2490) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2490) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2490) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2490) igt_core-INFO: Stack trace: (kms_flip:2490) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2490) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:2490) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:2490) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() (kms_flip:2490) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:2490) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2490) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2490) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest C-HDMI-A1: FAIL (1.992s) Subtest flip-vs-expired-vblank-interruptible: FAIL (22.381s) (kms_flip:2490) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2352: (kms_flip:2490) igt_kms-CRITICAL: Failed assertion: found_it (kms_flip:2490) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor (kms_flip:2490) igt_kms-CRITICAL: DPMS property not found on 390
Dmesg	<6> [273.445640] [IGT] kms_flip: starting dynamic subtest C-HDMI-A1 <7> [273.446616] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:417] <7> [273.446697] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:419] <7> [273.463009] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [273.463180] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B] <7> [273.463240] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.enable (expected yes, found no) <7> [273.463430] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.active (expected yes, found no) <7> [273.463576] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1) <7> [273.463720] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in lane_count (expected 4, found 0) <7> [273.463876] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [273.464018] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [273.464158] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [273.464298] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0) <7> [273.464436] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [273.464580] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0) <7> [273.464713] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [273.464860] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0) <7> [273.464993] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [273.465131] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [273.465265] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [273.465398] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [273.465530] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [273.465663] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [273.465806] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [273.465944] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0) <7> [273.466090] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [273.466224] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0) <7> [273.466358] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [273.466490] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0) <7> [273.466622] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [273.466754] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [273.466900] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [273.467032] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [273.467166] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [273.467299] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [273.467431] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [273.467565] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [273.467698] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [273.467844] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [273.467977] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0) <7> [273.468110] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0) <7> [273.468245] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in port_clock (expected 139929, found 0) <7> [273.468379] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:269:pipe B] fastset requirement not met, forcing full modeset <7> [273.468513] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:269:pipe B] releasing DPLL 0 <7> [273.468665] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no <7> [273.468835] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:269:pipe B] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x2 -> 0x0 <7> [273.468991] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:263:cursor B] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0 <7> [273.469141] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:269:pipe B] min cdclk: 69965 kHz -> 0 kHz <7> [273.469282] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:269:pipe B] enable: no [modeset] <7> [273.469419] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 1B] fb: [NOFB], visible: no <7> [273.469554] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:183:plane 2B] fb: [NOFB], visible: no <7> [273.469688] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:213:plane 3B] fb: [NOFB], visible: no <7> [273.469841] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:243:plane 4B] fb: [NOFB], visible: no <7> [273.469977] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:253:plane 5B] fb: [NOFB], visible: no <7> [273.470112] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:263:cursor B] fb: [NOFB], visible: no <7> [273.470371] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B <7> [273.481038] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B <7> [273.481205] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Disabling DP dual mode adaptor TMDS output <7> [273.486032] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:269:pipe B] <7> [273.486190] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0 <7> [273.486337] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B] <7> [273.486486] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C] <7> [273.486620] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D] <7> [273.486754] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A] <7> [273.486915] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B] <7> [273.487065] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C] <7> [273.487198] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:390:HDMI-A-1] <7> [273.487449] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1 <7> [273.487629] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3 <7> [273.487817] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:269:pipe B] <7> [273.488131] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C] <7> [273.488312] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C] <7> [273.488335] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:390:HDMI-A-1] <7> [273.488392] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:390:HDMI-A-1] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36) <7> [273.488538] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24) <7> [273.488666] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] hw max bpp: 24, pipe bpp: 24, dithering: 0 <7> [273.488812] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:389:DDI B/PHY B] [CRTC:387:pipe C] <7> [273.488942] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.enable (expected no, found yes) <7> [273.489079] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.active (expected no, found yes) <7> [273.489215] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2) <7> [273.489351] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in lane_count (expected 0, found 4) <7> [273.489486] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [273.489621] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [273.489756] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [273.489907] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360) <7> [273.490044] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [273.490180] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360) <7> [273.490318] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [273.490453] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096) <7> [273.490590] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [273.490727] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [273.490871] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [273.491007] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [273.491140] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [273.491274] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [273.491407] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [273.491539] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360) <7> [273.491671] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [273.491810] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360) <7> [273.491944] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [273.492077] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096) <7> [273.492210] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [273.492344] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [273.492476] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [273.492609] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [273.492742] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [273.492885] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [273.493018] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [273.493150] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [273.493283] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [273.493415] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [273.493549] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929) <7> [273.493683] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929) <7> [273.493830] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 0, found 139929) <7> [273.493967] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset <7> [273.494123] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no <7> [273.494257] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4 <7> [273.494412] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016 <7> [273.494544] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32 <7> [273.494674] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,twm, swm, stwm <7> [273.494810] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 <7> [273.494957] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 <7> [273.495091] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 <7> [273.495236] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 559716 num active planes 1 <7> [273.495373] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560 <7> [273.495507] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1 <7> [273.495654] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 0 kHz -> 69965 kHz <7> [273.495811] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:387:pipe C] allocated DPLL 0 <7> [273.495950] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:387:pipe C] reserving DPLL 0 <7> [273.496089] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: yes [modeset] <7> [273.496226] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [273.496362] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: C, pipe bpp: 24, dithering: 0 <7> [273.496496] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [273.496629] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [273.496763] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [273.496923] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [273.497057] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0 <7> [273.497190] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [273.497322] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [273.497455] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0 <7> [273.497589] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125 <7> [273.497721] 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> [273.497865] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 <7> [273.497999] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 <7> [273.498132] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [273.498265] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5 <7> [273.498398] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [273.498530] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0 <7> [273.498662] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0 <7> [273.498800] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [273.498935] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [273.499072] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [273.499208] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [273.499343] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [273.499476] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0 <7> [273.499610] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [273.499742] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [273.499890] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [273.500024] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [273.500159] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [273.500291] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [273.500425] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [273.500559] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [273.500692] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [273.500850] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [273.500985] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [273.501118] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [273.501249] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [FB:417] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [273.501383] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [273.501515] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [273.501649] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no <7> [273.501781] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no <7> [273.501927] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no <7> [273.502059] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no <7> [273.502191] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no <7> [273.502804] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3 <7> [273.502954] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_4 <7> [273.503115] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B] <7> [273.503253] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C] <7> [273.503389] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D] <7> [273.503523] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A] <7> [273.503655] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B] <7> [273.503795] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C] <7> [273.503963] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3 <7> [273.504132] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:387:pipe C] <7> [273.504270] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0 <7> [273.504447] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Enabling DP dual mode adaptor TMDS output <7> [273.509236] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B <7> [273.509410] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe C <7> [273.509630] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: processing event-flags 0x0000000d <7> [273.528579] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: processing event-flags 0x0000000a <7> [273.528752] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: creating arb_session after invalidation <7> [273.548614] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:390:HDMI-A-1] <7> [273.549418] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C] <7> [273.557285] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP ARB session is alive <6> [275.440155] [IGT] kms_flip: finished subtest C-HDMI-A1, FAIL <6> [275.441275] [IGT] kms_flip: finished subtest flip-vs-expired-vblank-interruptible, FAIL <7> [275.443934] i915 0000:00:02.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:419] from all active usage due to RMFB ioctl <7> [275.444149] i915 0000:00:02.0: [drm:atomic_remove_fb] Disabling [PLANE:271:plane 1C] because [FB:419] is removed <7> [275.444191] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0 <7> [275.444356] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] level wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm <7> [275.444525] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [275.444657] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [275.444808] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] min_ddb 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [275.444972] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 0 num active planes 0 <7> [275.445142] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0 <7> [275.445278] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1 <6> [275.465644] [IGT] kms_flip: exiting, ret=98 <7> [275.475824] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:390:HDMI-A-1] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36) <7> [275.476003] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24) <7> [275.476136] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0 <7> [275.476287] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:389:DDI B/PHY B] [CRTC:151:pipe A] <7> [275.476420] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [275.476561] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [275.476699] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [275.476848] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [275.476991] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [275.477130] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [275.477268] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [275.477412] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360) <7> [275.477546] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [275.477681] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360) <7> [275.477823] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [275.477958] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096) <7> [275.478092] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [275.478226] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [275.478358] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [275.478491] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [275.478623] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [275.478756] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [275.478908] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [275.479041] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360) <7> [275.479173] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [275.479306] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360) <7> [275.479437] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [275.479569] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096) <7> [275.479701] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [275.479842] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [275.479974] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [275.480106] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [275.480237] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [275.480368] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [275.480500] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [275.480633] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [275.480771] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [275.480906] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [275.481038] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929) <7> [275.481171] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929) <7> [275.481304] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 139929) <7> [275.481437] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [275.481570] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.enable (expected yes, found no) <7> [275.481703] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.active (expected yes, found no) <7> [275.481847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1) <7> [275.481981] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in lane_count (expected 4, found 0) <7> [275.482114] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [275.482247] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [275.482379] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [275.482510] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0) <7> [275.482642] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [275.482779] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0) <7> [275.482912] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [275.483043] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0) <7> [275.483175] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [275.483308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [275.483440] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [275.483572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [275.483703] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [275.483952] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [275.484084] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [275.484216] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0) <7> [275.484347] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [275.484479] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0) <7> [275.484610] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [275.484742] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0) <7> [275.484940] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [275.485075] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [275.485209] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [275.485343] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [275.485475] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [275.485607] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [275.485753] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [275.485897] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [275.486030] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [275.486162] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [275.486294] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0) <7> [275.486426] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0) <7> [275.486558] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 139929, found 0) <7> [275.486690] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset <7> [275.486830] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:387:pipe C] releasing DPLL 0 <7> [275.486999] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x4 -> 0x1 <7> [275.487133] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x4 -> 0x1 <7> [275.487266] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016 <7> [275.487397] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32 <7> [275.487532] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [275.487665] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 <7> [275.487804] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 <7> [275.487935] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 <7> [275.488066] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0 <7> [275.488211] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 559716 num active planes 1 <7> [275.488349] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560 <7> [275.488483] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1 <7> [275.488639] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 69965 kHz <7> [275.488778] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 69965 kHz -> 0 kHz <7> [275.488931] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:151:pipe A] allocated DPLL 0 <7> [275.489072] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:151:pipe A] reserving DPLL 0 <7> [275.489213] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: yes [modeset] <7> [275.489351] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [275.489487] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0 <7> [275.489621] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [275.489756] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [275.489986] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [275.490120] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [275.490253] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0 <7> [275.490386] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [275.490518] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [275.490649] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0 <7> [275.491434] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125 <7> [275.491575] 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> [275.491709] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 <7> [275.491853] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 <7> [275.491988] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [275.492139] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5 <7> [275.492274] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [275.492415] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0 <7> [275.492547] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0 <7> [275.492682] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [275.492825] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [275.492958] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [275.493091] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [275.493223] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [275.493354] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0 <7> [275.493486] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [275.493621] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [275.493752] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [275.493922] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [275.494054] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [275.494184] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [275.494314] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [275.494446] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [275.494577] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [275.494708] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [275.494848] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [275.494978] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [275.495109] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:416] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes <7> [275.495241] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [275.495372] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [275.495504] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [275.495636] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [275.495773] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [275.495904] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [275.496035] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [275.496166] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: no [modeset] <7> [275.496297] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [NOFB], visible: no <7> [275.496428] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no <7> [275.496557] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no <7> [275.496687] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no <7> [275.496827] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no <7> [275.496957] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no <7> [275.497230] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe C <7> [275.503948] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B <7> [275.504112] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Disabling DP dual mode adaptor TMDS output <7> [275.508893] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x4, on? 1) for [CRTC:387:pipe C] <7> [275.509054] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0 <7> [275.509202] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B] <7> [275.509338] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C] <7> [275.509471] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D] <7> [275.509606] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A] <7> [275.509742] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B] <7> [275.509891] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C] <7> [275.510129] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A] <7> [275.510269] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0 <7> [275.510449] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Enabling DP dual mode adaptor TMDS output <7> [275.515383] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B <7> [275.515561] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [275.515825] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: processing event-flags 0x0000000d <7> [275.534747] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: processing event-flags 0x0000000a <7> [275.534891] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: creating arb_session after invalidation <7> [275.534940] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1 <7> [275.535086] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A] <7> [275.554023] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:390:HDMI-A-1] <7> [275.554237] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A] <7> [275.554737] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_4 <7> [275.554927] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C] <7> [275.555149] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3 <7> [275.555448] i915 0000:00:02.0: [drm:drm_client_dev_restore] fbdev: ret=0 <7> [275.562984] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP ARB session is alive

Detail

Value

Duration

1.99 seconds

Hostname

shard-rkl-5

Igt-Version

IGT-Version: 2.4-ga22943872 (x86_64) (Linux: 7.1.0-rc2-CI_DRM_18452-g680a4832a818+ x86_64)

Out

Starting dynamic subtest: C-HDMI-A1
  1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest C-HDMI-A1: FAIL (1.992s)
Subtest flip-vs-expired-vblank-interruptible: FAIL (22.381s)
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2352 kmstest_set_connector_dpms()
  #2 ../lib/igt_core.c:2961 igt_atexit_handler()
  #3 [erand48_r+0x1d6]
  #4 [exit+0x1e]
  #5 ../lib/igt_core.c:2416 igt_exit()
  #6 [main+0x3f]
  #7 [__libc_init_first+0x8a]
  #8 [__libc_start_main+0x8b]
  #9 [_start+0x25]

Err

Starting dynamic subtest: C-HDMI-A1
(kms_flip:2490) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2490) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2490) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest C-HDMI-A1 failed.
**** DEBUG ****
(kms_flip:2490) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000001, size=0)
(kms_flip:2490) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2490) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2490) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=7680)
(kms_flip:2490) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2490) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000001, size=0)
(kms_flip:2490) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2490) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2490) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680)
(kms_flip:2490) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2490) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2490) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2490) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS
(kms_flip:2490) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2490) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2490) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS
(kms_flip:2490) igt_kms-INFO:   1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 
(kms_flip:2490) DEBUG: No stale events found
(kms_flip:2490) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2490) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2490) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 273.666046
current_received_ts = 273.665405
current_seq = 207
count = 0
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 27us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.666046
last_received_ts = 273.665405
last_seq = 207
current_ts = 273.685028
current_received_ts = 273.684357
current_seq = 208
count = 1
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.685028
last_received_ts = 273.684357
last_seq = 208
current_ts = 273.704010
current_received_ts = 273.703461
current_seq = 209
count = 2
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.704010
last_received_ts = 273.703461
last_seq = 209
current_ts = 273.722961
current_received_ts = 273.722351
current_seq = 210
count = 3
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 29us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.722961
last_received_ts = 273.722351
last_seq = 210
current_ts = 273.741943
current_received_ts = 273.741333
current_seq = 211
count = 4
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 27us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.741943
last_received_ts = 273.741333
last_seq = 211
current_ts = 273.760925
current_received_ts = 273.760345
current_seq = 212
count = 5
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 29us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.760925
last_received_ts = 273.760345
last_seq = 212
current_ts = 273.779877
current_received_ts = 273.779266
current_seq = 213
count = 6
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 29us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.779877
last_received_ts = 273.779266
last_seq = 213
current_ts = 273.798859
current_received_ts = 273.798248
current_seq = 214
count = 7
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.798859
last_received_ts = 273.798248
last_seq = 214
current_ts = 273.817841
current_received_ts = 273.817200
current_seq = 215
count = 8
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.817841
last_received_ts = 273.817200
last_seq = 215
current_ts = 273.836823
current_received_ts = 273.836182
current_seq = 216
count = 9
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.836823
last_received_ts = 273.836182
last_seq = 216
current_ts = 273.855804
current_received_ts = 273.855225
current_seq = 217
count = 10
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.855804
last_received_ts = 273.855225
last_seq = 217
current_ts = 273.874756
current_received_ts = 273.874237
current_seq = 218
count = 11
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.874756
last_received_ts = 273.874237
last_seq = 218
current_ts = 273.893738
current_received_ts = 273.893219
current_seq = 219
count = 12
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.893738
last_received_ts = 273.893219
last_seq = 219
current_ts = 273.912720
current_received_ts = 273.912079
current_seq = 220
count = 13
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 26us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.912720
last_received_ts = 273.912079
last_seq = 220
current_ts = 273.931671
current_received_ts = 273.931122
current_seq = 221
count = 14
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 26us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.931671
last_received_ts = 273.931122
last_seq = 221
current_ts = 273.950653
current_received_ts = 273.950073
current_seq = 222
count = 15
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 30us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.950653
last_received_ts = 273.950073
last_seq = 222
current_ts = 273.969635
current_received_ts = 273.969055
current_seq = 223
count = 16
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.969635
last_received_ts = 273.969055
last_seq = 223
current_ts = 273.988617
current_received_ts = 273.987976
current_seq = 224
count = 17
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 273.988617
last_received_ts = 273.987976
last_seq = 224
current_ts = 274.007599
current_received_ts = 274.007050
current_seq = 225
count = 18
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.007599
last_received_ts = 274.007050
last_seq = 225
current_ts = 274.026550
current_received_ts = 274.025970
current_seq = 226
count = 19
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 59us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.026550
last_received_ts = 274.025970
last_seq = 226
current_ts = 274.045532
current_received_ts = 274.044922
current_seq = 227
count = 20
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.045532
last_received_ts = 274.044922
last_seq = 227
current_ts = 274.064484
current_received_ts = 274.063934
current_seq = 228
count = 21
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.064484
last_received_ts = 274.063934
last_seq = 228
current_ts = 274.083496
current_received_ts = 274.082886
current_seq = 229
count = 22
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.083496
last_received_ts = 274.082886
last_seq = 229
current_ts = 274.102448
current_received_ts = 274.101837
current_seq = 230
count = 23
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.102448
last_received_ts = 274.101837
last_seq = 230
current_ts = 274.121429
current_received_ts = 274.120819
current_seq = 231
count = 24
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 64us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.121429
last_received_ts = 274.120819
last_seq = 231
current_ts = 274.140381
current_received_ts = 274.139771
current_seq = 232
count = 25
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.140381
last_received_ts = 274.139771
last_seq = 232
current_ts = 274.159393
current_received_ts = 274.158783
current_seq = 233
count = 26
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.159393
last_received_ts = 274.158783
last_seq = 233
current_ts = 274.178345
current_received_ts = 274.177734
current_seq = 234
count = 27
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 27us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.178345
last_received_ts = 274.177734
last_seq = 234
current_ts = 274.197327
current_received_ts = 274.196686
current_seq = 235
count = 28
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.197327
last_received_ts = 274.196686
last_seq = 235
current_ts = 274.216278
current_received_ts = 274.215668
current_seq = 236
count = 29
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.216278
last_received_ts = 274.215668
last_seq = 236
current_ts = 274.235260
current_received_ts = 274.234711
current_seq = 237
count = 30
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.235260
last_received_ts = 274.234711
last_seq = 237
current_ts = 274.254242
current_received_ts = 274.253693
current_seq = 238
count = 31
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.254242
last_received_ts = 274.253693
last_seq = 238
current_ts = 274.273224
current_received_ts = 274.272614
current_seq = 239
count = 32
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.273224
last_received_ts = 274.272614
last_seq = 239
current_ts = 274.292206
current_received_ts = 274.291595
current_seq = 240
count = 33
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.292206
last_received_ts = 274.291595
last_seq = 240
current_ts = 274.311157
current_received_ts = 274.310547
current_seq = 241
count = 34
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.311157
last_received_ts = 274.310547
last_seq = 241
current_ts = 274.330139
current_received_ts = 274.329498
current_seq = 242
count = 35
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.330139
last_received_ts = 274.329498
last_seq = 242
current_ts = 274.349121
current_received_ts = 274.348511
current_seq = 243
count = 36
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 28us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.349121
last_received_ts = 274.348511
last_seq = 243
current_ts = 274.368103
current_received_ts = 274.367493
current_seq = 244
count = 37
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.368103
last_received_ts = 274.367493
last_seq = 244
current_ts = 274.387054
current_received_ts = 274.386444
current_seq = 245
count = 38
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.387054
last_received_ts = 274.386444
last_seq = 245
current_ts = 274.406036
current_received_ts = 274.405396
current_seq = 246
count = 39
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.406036
last_received_ts = 274.405396
last_seq = 246
current_ts = 274.425018
current_received_ts = 274.424377
current_seq = 247
count = 40
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 28us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.425018
last_received_ts = 274.424377
last_seq = 247
current_ts = 274.443970
current_received_ts = 274.443481
current_seq = 248
count = 41
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.443970
last_received_ts = 274.443481
last_seq = 248
current_ts = 274.462952
current_received_ts = 274.462372
current_seq = 249
count = 42
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.462952
last_received_ts = 274.462372
last_seq = 249
current_ts = 274.481934
current_received_ts = 274.481354
current_seq = 250
count = 43
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 25us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.481934
last_received_ts = 274.481354
last_seq = 250
current_ts = 274.500916
current_received_ts = 274.500305
current_seq = 251
count = 44
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 30us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.500916
last_received_ts = 274.500305
last_seq = 251
current_ts = 274.519867
current_received_ts = 274.519287
current_seq = 252
count = 45
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.519867
last_received_ts = 274.519287
last_seq = 252
current_ts = 274.538849
current_received_ts = 274.538208
current_seq = 253
count = 46
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.538849
last_received_ts = 274.538208
last_seq = 253
current_ts = 274.557831
current_received_ts = 274.557190
current_seq = 254
count = 47
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.557831
last_received_ts = 274.557190
last_seq = 254
current_ts = 274.576813
current_received_ts = 274.576202
current_seq = 255
count = 48
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.576813
last_received_ts = 274.576202
last_seq = 255
current_ts = 274.595764
current_received_ts = 274.595215
current_seq = 256
count = 49
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.595764
last_received_ts = 274.595215
last_seq = 256
current_ts = 274.614746
current_received_ts = 274.614197
current_seq = 257
count = 50
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.614746
last_received_ts = 274.614197
last_seq = 257
current_ts = 274.633728
current_received_ts = 274.633118
current_seq = 258
count = 51
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.633728
last_received_ts = 274.633118
last_seq = 258
current_ts = 274.652679
current_received_ts = 274.652100
current_seq = 259
count = 52
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.652679
last_received_ts = 274.652100
last_seq = 259
current_ts = 274.671692
current_received_ts = 274.671082
current_seq = 260
count = 53
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 34us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.671692
last_received_ts = 274.671082
last_seq = 260
current_ts = 274.690643
current_received_ts = 274.690002
current_seq = 261
count = 54
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 43us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.690643
last_received_ts = 274.690002
last_seq = 261
current_ts = 274.709625
current_received_ts = 274.709045
current_seq = 262
count = 55
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 64us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.709625
last_received_ts = 274.709045
last_seq = 262
current_ts = 274.728607
current_received_ts = 274.728027
current_seq = 263
count = 56
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.728607
last_received_ts = 274.728027
last_seq = 263
current_ts = 274.747589
current_received_ts = 274.746979
current_seq = 264
count = 57
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.747589
last_received_ts = 274.746979
last_seq = 264
current_ts = 274.766541
current_received_ts = 274.765961
current_seq = 265
count = 58
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 65us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.766541
last_received_ts = 274.765961
last_seq = 265
current_ts = 274.785522
current_received_ts = 274.784912
current_seq = 266
count = 59
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.785522
last_received_ts = 274.784912
last_seq = 266
current_ts = 274.804504
current_received_ts = 274.803864
current_seq = 267
count = 60
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 30us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.804504
last_received_ts = 274.803864
last_seq = 267
current_ts = 274.823456
current_received_ts = 274.822815
current_seq = 268
count = 61
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.823456
last_received_ts = 274.822815
last_seq = 268
current_ts = 274.842438
current_received_ts = 274.841858
current_seq = 269
count = 62
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.842438
last_received_ts = 274.841858
last_seq = 269
current_ts = 274.861420
current_received_ts = 274.860809
current_seq = 270
count = 63
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.861420
last_received_ts = 274.860809
last_seq = 270
current_ts = 274.880402
current_received_ts = 274.879791
current_seq = 271
count = 64
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.880402
last_received_ts = 274.879791
last_seq = 271
current_ts = 274.899353
current_received_ts = 274.898834
current_seq = 272
count = 65
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 26us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.899353
last_received_ts = 274.898834
last_seq = 272
current_ts = 274.918335
current_received_ts = 274.917725
current_seq = 273
count = 66
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.918335
last_received_ts = 274.917725
last_seq = 273
current_ts = 274.937317
current_received_ts = 274.936676
current_seq = 274
count = 67
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.937317
last_received_ts = 274.936676
last_seq = 274
current_ts = 274.956299
current_received_ts = 274.955688
current_seq = 275
count = 68
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.956299
last_received_ts = 274.955688
last_seq = 275
current_ts = 274.975250
current_received_ts = 274.974670
current_seq = 276
count = 69
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 30us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.975250
last_received_ts = 274.974670
last_seq = 276
current_ts = 274.994232
current_received_ts = 274.993622
current_seq = 277
count = 70
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 274.994232
last_received_ts = 274.993622
last_seq = 277
current_ts = 275.013184
current_received_ts = 275.012604
current_seq = 278
count = 71
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 30us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.013184
last_received_ts = 275.012604
last_seq = 278
current_ts = 275.032196
current_received_ts = 275.031586
current_seq = 279
count = 72
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 26us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.032196
last_received_ts = 275.031586
last_seq = 279
current_ts = 275.051147
current_received_ts = 275.050568
current_seq = 280
count = 73
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.051147
last_received_ts = 275.050568
last_seq = 280
current_ts = 275.070129
current_received_ts = 275.069489
current_seq = 281
count = 74
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.070129
last_received_ts = 275.069489
last_seq = 281
current_ts = 275.089111
current_received_ts = 275.088531
current_seq = 282
count = 75
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 55us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.089111
last_received_ts = 275.088531
last_seq = 282
current_ts = 275.108063
current_received_ts = 275.107483
current_seq = 283
count = 76
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.108063
last_received_ts = 275.107483
last_seq = 283
current_ts = 275.127045
current_received_ts = 275.126434
current_seq = 284
count = 77
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.127045
last_received_ts = 275.126434
last_seq = 284
current_ts = 275.146027
current_received_ts = 275.145416
current_seq = 285
count = 78
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.146027
last_received_ts = 275.145416
last_seq = 285
current_ts = 275.165009
current_received_ts = 275.164520
current_seq = 286
count = 79
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.165009
last_received_ts = 275.164520
last_seq = 286
current_ts = 275.183960
current_received_ts = 275.183350
current_seq = 287
count = 80
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.183960
last_received_ts = 275.183350
last_seq = 287
current_ts = 275.202942
current_received_ts = 275.202362
current_seq = 288
count = 81
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.202942
last_received_ts = 275.202362
last_seq = 288
current_ts = 275.221924
current_received_ts = 275.221344
current_seq = 289
count = 82
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 26us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.221924
last_received_ts = 275.221344
last_seq = 289
current_ts = 275.240906
current_received_ts = 275.240326
current_seq = 290
count = 83
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 30us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.240906
last_received_ts = 275.240326
last_seq = 290
current_ts = 275.259888
current_received_ts = 275.259216
current_seq = 291
count = 84
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.259888
last_received_ts = 275.259216
last_seq = 291
current_ts = 275.278839
current_received_ts = 275.278198
current_seq = 292
count = 85
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.278839
last_received_ts = 275.278198
last_seq = 292
current_ts = 275.297821
current_received_ts = 275.297241
current_seq = 293
count = 86
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 31us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.297821
last_received_ts = 275.297241
last_seq = 293
current_ts = 275.316803
current_received_ts = 275.316254
current_seq = 294
count = 87
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.316803
last_received_ts = 275.316254
last_seq = 294
current_ts = 275.335754
current_received_ts = 275.335205
current_seq = 295
count = 88
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.335754
last_received_ts = 275.335205
last_seq = 295
current_ts = 275.354736
current_received_ts = 275.354095
current_seq = 296
count = 89
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.354736
last_received_ts = 275.354095
last_seq = 296
current_ts = 275.373718
current_received_ts = 275.373108
current_seq = 297
count = 90
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 25us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.373718
last_received_ts = 275.373108
last_seq = 297
current_ts = 275.392700
current_received_ts = 275.392090
current_seq = 298
count = 91
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.392700
last_received_ts = 275.392090
last_seq = 298
current_ts = 275.411652
current_received_ts = 275.411102
current_seq = 299
count = 92
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 32us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.411652
last_received_ts = 275.411102
last_seq = 299
current_ts = 275.430634
current_received_ts = 275.429993
current_seq = 300
count = 93
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 33us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.430634
last_received_ts = 275.429993
last_seq = 300
current_ts = 275.449615
current_received_ts = 275.449097
current_seq = 301
count = 94
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 28us
(kms_flip:2490) DEBUG: name = flip
last_ts = 275.449615
last_received_ts = 275.449097
last_seq = 301
current_ts = 275.468567
current_received_ts = 275.467957
current_seq = 302
count = 95
seq_step = 1
(kms_flip:2490) DEBUG: Vblank took 837us
(kms_flip:2490) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2490) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2490) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2490) igt_core-INFO: Stack trace:
(kms_flip:2490) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2490) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2490) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2490) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2490) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2490) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2490) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2490) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-HDMI-A1: FAIL (1.992s)
Subtest flip-vs-expired-vblank-interruptible: FAIL (22.381s)
(kms_flip:2490) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2352:
(kms_flip:2490) igt_kms-CRITICAL: Failed assertion: found_it
(kms_flip:2490) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
(kms_flip:2490) igt_kms-CRITICAL: DPMS property not found on 390

Dmesg

<6> [273.445640] [IGT] kms_flip: starting dynamic subtest C-HDMI-A1

<7> [273.446616] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:417]

<7> [273.446697] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:419]

<7> [273.463009] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

<7> [273.463180] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [273.468513] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:269:pipe B] releasing DPLL 0

<7> [273.468665] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no

<7> [273.468835] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:269:pipe B] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x2 -> 0x0

<7> [273.468991] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:263:cursor B] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0

<7> [273.469141] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:269:pipe B] min cdclk: 69965 kHz -> 0 kHz

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

<7> [273.469419] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 1B] fb: [NOFB], visible: no

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

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

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

<7> [273.469977] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:253:plane 5B] fb: [NOFB], visible: no

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

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

<7> [273.481038] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B

<7> [273.481205] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Disabling DP dual mode adaptor TMDS output

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

<7> [273.486190] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0

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

<7> [273.486486] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]

<7> [273.486620] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]

<7> [273.486754] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]

<7> [273.486915] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]

<7> [273.487065] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]

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

<7> [273.487449] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1

<7> [273.487629] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3

<7> [273.487817] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:269:pipe B]

<7> [273.488131] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]

<7> [273.488312] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]

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

<7> [273.488392] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:390:HDMI-A-1] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)

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

<7> [273.488666] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] hw max bpp: 24, pipe bpp: 24, dithering: 0

<7> [273.488812] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:389:DDI B/PHY B] [CRTC:387:pipe C]

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

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

<7> [273.489215] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)

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

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

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

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

<7> [273.489907] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360)

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

<7> [273.490180] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360)

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

<7> [273.490453] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096)

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

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

<7> [273.490871] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)

<7> [273.491007] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)

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

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

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

<7> [273.491539] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360)

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

<7> [273.491810] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360)

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

<7> [273.492077] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096)

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

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

<7> [273.492476] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)

<7> [273.492609] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)

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

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

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

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

<7> [273.493283] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)

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

<7> [273.493549] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929)

<7> [273.493683] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929)

<7> [273.493830] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 0, found 139929)

<7> [273.493967] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset

<7> [273.494123] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no

<7> [273.494257] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4

<7> [273.494412] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016

<7> [273.494544] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32

<7> [273.494674] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm

<7> [273.494810] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0

<7> [273.494957] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0

<7> [273.495091] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0

<7> [273.495236] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 559716 num active planes 1

<7> [273.495373] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560

<7> [273.495507] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1

<7> [273.495654] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 0 kHz -> 69965 kHz

<7> [273.495811] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:387:pipe C] allocated DPLL 0

<7> [273.495950] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:387:pipe C] reserving DPLL 0

<7> [273.496089] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: yes [modeset]

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

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

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

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

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

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

<7> [273.497057] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0

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

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

<7> [273.497455] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0

<7> [273.497589] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125

<7> [273.497721] 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> [273.497865] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5

<7> [273.497999] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5

<7> [273.498132] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [273.498265] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5

<7> [273.498398] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [273.498530] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0

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

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

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

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

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

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

<7> [273.499476] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [273.501649] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no

<7> [273.501781] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no

<7> [273.501927] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no

<7> [273.502059] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no

<7> [273.502191] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no

<7> [273.502804] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3

<7> [273.502954] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_4

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

<7> [273.503253] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]

<7> [273.503389] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]

<7> [273.503523] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]

<7> [273.503655] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]

<7> [273.503795] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]

<7> [273.503963] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3

<7> [273.504132] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:387:pipe C]

<7> [273.504270] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0

<7> [273.504447] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Enabling DP dual mode adaptor TMDS output

<7> [273.509236] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B

<7> [273.509410] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe C

<7> [273.509630] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: processing event-flags 0x0000000d

<7> [273.528579] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: processing event-flags 0x0000000a

<7> [273.528752] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: creating arb_session after invalidation

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

<7> [273.549418] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C]

<7> [273.557285] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP ARB session is alive

<6> [275.440155] [IGT] kms_flip: finished subtest C-HDMI-A1, FAIL

<6> [275.441275] [IGT] kms_flip: finished subtest flip-vs-expired-vblank-interruptible, FAIL

<7> [275.443934] i915 0000:00:02.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:419] from all active usage due to RMFB ioctl

<7> [275.444149] i915 0000:00:02.0: [drm:atomic_remove_fb] Disabling [PLANE:271:plane 1C] because [FB:419] is removed

<7> [275.444191] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0

<7> [275.444356] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm

<7> [275.444525] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [275.444657] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [275.444808] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:271:plane 1C] min_ddb 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [275.444972] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 0 num active planes 0

<7> [275.445142] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0

<7> [275.445278] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1

<6> [275.465644] [IGT] kms_flip: exiting, ret=98

<7> [275.475824] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:390:HDMI-A-1] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)

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

<7> [275.476136] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0

<7> [275.476287] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:389:DDI B/PHY B] [CRTC:151:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [275.481847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1)

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

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

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

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

<7> [275.482510] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0)

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

<7> [275.482779] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0)

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

<7> [275.483043] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0)

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

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

<7> [275.483440] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)

<7> [275.483572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)

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

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

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

<7> [275.484216] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0)

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

<7> [275.484479] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0)

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

<7> [275.484742] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0)

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

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

<7> [275.485209] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)

<7> [275.485343] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)

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

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

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

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

<7> [275.486030] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)

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

<7> [275.486294] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0)

<7> [275.486426] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0)

<7> [275.486558] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in port_clock (expected 139929, found 0)

<7> [275.486690] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset

<7> [275.486830] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:387:pipe C] releasing DPLL 0

<7> [275.486999] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x4 -> 0x1

<7> [275.487133] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x4 -> 0x1

<7> [275.487266] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016

<7> [275.487397] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32

<7> [275.487532] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm

<7> [275.487665] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0

<7> [275.487804] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0

<7> [275.487935] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0

<7> [275.488066] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0

<7> [275.488211] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 559716 num active planes 1

<7> [275.488349] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560

<7> [275.488483] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1

<7> [275.488639] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 69965 kHz

<7> [275.488778] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 69965 kHz -> 0 kHz

<7> [275.488931] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:151:pipe A] allocated DPLL 0

<7> [275.489072] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:151:pipe A] reserving DPLL 0

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

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

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

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

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

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

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

<7> [275.490253] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0

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

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

<7> [275.490649] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0

<7> [275.491434] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125

<7> [275.491575] 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> [275.491709] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5

<7> [275.491853] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5

<7> [275.491988] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [275.492139] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5

<7> [275.492274] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [275.492415] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0

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

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

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

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

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

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

<7> [275.493354] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0

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

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

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

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

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

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

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

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

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

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

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

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

<7> [275.495109] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:416] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes

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

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

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

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

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

<7> [275.495904] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no

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

<7> [275.496166] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: no [modeset]

<7> [275.496297] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [NOFB], visible: no

<7> [275.496428] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no

<7> [275.496557] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no

<7> [275.496687] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no

<7> [275.496827] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no

<7> [275.496957] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no

<7> [275.497230] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe C

<7> [275.503948] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B

<7> [275.504112] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Disabling DP dual mode adaptor TMDS output

<7> [275.508893] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x4, on? 1) for [CRTC:387:pipe C]

<7> [275.509054] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0

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

<7> [275.509338] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]

<7> [275.509471] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]

<7> [275.509606] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]

<7> [275.509742] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]

<7> [275.509891] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]

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

<7> [275.510269] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0

<7> [275.510449] i915 0000:00:02.0: [drm:intel_dp_dual_mode_set_tmds_output [i915]] Enabling DP dual mode adaptor TMDS output

<7> [275.515383] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B

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

<7> [275.515825] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: processing event-flags 0x0000000d

<7> [275.534747] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: processing event-flags 0x0000000a

<7> [275.534891] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP: creating arb_session after invalidation

<7> [275.534940] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1

<7> [275.535086] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]

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

<7> [275.554237] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]

<7> [275.554737] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_4

<7> [275.554927] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C]

<7> [275.555149] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3

<7> [275.555448] i915 0000:00:02.0: [drm:drm_client_dev_restore] fbdev: ret=0

<7> [275.562984] i915 0000:00:02.0: [drm:pxp_session_work [i915]] PXP ARB session is alive

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