igt@kms_flip@flip-vs-expired-vblank-interruptible@c-edp1 on shard-mtlp@IGTPW

Detail	Value
Duration	1.87 seconds
Hostname	shard-mtlp-1
Igt-Version	IGT-Version: 2.4-gfa229a9c1 (x86_64) (Linux: 7.0.0-CI_DRM_18366-gd431883e767c+ x86_64)
Out	Starting dynamic subtest: C-eDP1 2880x1800: 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa 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-eDP1: FAIL (1.870s)
Err	Starting dynamic subtest: C-eDP1 (kms_flip:2348) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2348) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2348) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest C-eDP1 failed. ** DEBUG (kms_flip:2348) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0) (kms_flip:2348) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2348) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2348) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=11520) (kms_flip:2348) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:2348) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0) (kms_flip:2348) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2348) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2348) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=11520) (kms_flip:2348) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd) (kms_flip:2348) intel_allocator_reloc-DEBUG: Using reloc allocator (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd) (kms_flip:2348) intel_allocator_reloc-DEBUG: Using reloc allocator (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd) (kms_flip:2348) intel_allocator_reloc-DEBUG: Using reloc allocator (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd) (kms_flip:2348) intel_allocator_reloc-DEBUG: Using reloc allocator (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2348) igt_kms-INFO: 2880x1800: 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa (kms_flip:2348) DEBUG: No stale events found (kms_flip:2348) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0 (kms_flip:2348) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0 (kms_flip:2348) DEBUG: name = flip last_ts = 0.000000 last_received_ts = 0.000000 last_seq = 0 current_ts = 77.116379 current_received_ts = 77.115982 current_seq = 4 count = 0 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 10us (kms_flip:2348) DEBUG: name = flip last_ts = 77.116379 last_received_ts = 77.115982 last_seq = 4 current_ts = 77.127487 current_received_ts = 77.127075 current_seq = 5 count = 1 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 2us (kms_flip:2348) DEBUG: name = flip last_ts = 77.127487 last_received_ts = 77.127075 last_seq = 5 current_ts = 77.138588 current_received_ts = 77.138184 current_seq = 6 count = 2 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.138588 last_received_ts = 77.138184 last_seq = 6 current_ts = 77.149689 current_received_ts = 77.149292 current_seq = 7 count = 3 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.149689 last_received_ts = 77.149292 last_seq = 7 current_ts = 77.160797 current_received_ts = 77.160400 current_seq = 8 count = 4 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 6us (kms_flip:2348) DEBUG: name = flip last_ts = 77.160797 last_received_ts = 77.160400 last_seq = 8 current_ts = 77.171906 current_received_ts = 77.171501 current_seq = 9 count = 5 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.171906 last_received_ts = 77.171501 last_seq = 9 current_ts = 77.183006 current_received_ts = 77.182617 current_seq = 10 count = 6 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.183006 last_received_ts = 77.182617 last_seq = 10 current_ts = 77.194115 current_received_ts = 77.193710 current_seq = 11 count = 7 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.194115 last_received_ts = 77.193710 last_seq = 11 current_ts = 77.205215 current_received_ts = 77.204819 current_seq = 12 count = 8 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.205215 last_received_ts = 77.204819 last_seq = 12 current_ts = 77.216316 current_received_ts = 77.215919 current_seq = 13 count = 9 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.216316 last_received_ts = 77.215919 last_seq = 13 current_ts = 77.227425 current_received_ts = 77.227028 current_seq = 14 count = 10 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.227425 last_received_ts = 77.227028 last_seq = 14 current_ts = 77.238525 current_received_ts = 77.238121 current_seq = 15 count = 11 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.238525 last_received_ts = 77.238121 last_seq = 15 current_ts = 77.249634 current_received_ts = 77.249237 current_seq = 16 count = 12 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 5us (kms_flip:2348) DEBUG: name = flip last_ts = 77.249634 last_received_ts = 77.249237 last_seq = 16 current_ts = 77.260735 current_received_ts = 77.260330 current_seq = 17 count = 13 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.260735 last_received_ts = 77.260330 last_seq = 17 current_ts = 77.271843 current_received_ts = 77.271446 current_seq = 18 count = 14 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.271843 last_received_ts = 77.271446 last_seq = 18 current_ts = 77.282944 current_received_ts = 77.282539 current_seq = 19 count = 15 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.282944 last_received_ts = 77.282539 last_seq = 19 current_ts = 77.294052 current_received_ts = 77.293648 current_seq = 20 count = 16 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.294052 last_received_ts = 77.293648 last_seq = 20 current_ts = 77.305161 current_received_ts = 77.304756 current_seq = 21 count = 17 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.305161 last_received_ts = 77.304756 last_seq = 21 current_ts = 77.316261 current_received_ts = 77.315865 current_seq = 22 count = 18 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.316261 last_received_ts = 77.315865 last_seq = 22 current_ts = 77.327370 current_received_ts = 77.326965 current_seq = 23 count = 19 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.327370 last_received_ts = 77.326965 last_seq = 23 current_ts = 77.338470 current_received_ts = 77.338074 current_seq = 24 count = 20 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.338470 last_received_ts = 77.338074 last_seq = 24 current_ts = 77.349571 current_received_ts = 77.349167 current_seq = 25 count = 21 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.349571 last_received_ts = 77.349167 last_seq = 25 current_ts = 77.360680 current_received_ts = 77.360275 current_seq = 26 count = 22 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.360680 last_received_ts = 77.360275 last_seq = 26 current_ts = 77.371780 current_received_ts = 77.371384 current_seq = 27 count = 23 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.371780 last_received_ts = 77.371384 last_seq = 27 current_ts = 77.382889 current_received_ts = 77.382484 current_seq = 28 count = 24 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.382889 last_received_ts = 77.382484 last_seq = 28 current_ts = 77.393997 current_received_ts = 77.393593 current_seq = 29 count = 25 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.393997 last_received_ts = 77.393593 last_seq = 29 current_ts = 77.405098 current_received_ts = 77.404694 current_seq = 30 count = 26 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 5us (kms_flip:2348) DEBUG: name = flip last_ts = 77.405098 last_received_ts = 77.404694 last_seq = 30 current_ts = 77.416199 current_received_ts = 77.415794 current_seq = 31 count = 27 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.416199 last_received_ts = 77.415794 last_seq = 31 current_ts = 77.427307 current_received_ts = 77.426910 current_seq = 32 count = 28 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.427307 last_received_ts = 77.426910 last_seq = 32 current_ts = 77.438416 current_received_ts = 77.438019 current_seq = 33 count = 29 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.438416 last_received_ts = 77.438019 last_seq = 33 current_ts = 77.449516 current_received_ts = 77.449112 current_seq = 34 count = 30 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.449516 last_received_ts = 77.449112 last_seq = 34 current_ts = 77.460625 current_received_ts = 77.460220 current_seq = 35 count = 31 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.460625 last_received_ts = 77.460220 last_seq = 35 current_ts = 77.471725 current_received_ts = 77.471329 current_seq = 36 count = 32 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.471725 last_received_ts = 77.471329 last_seq = 36 current_ts = 77.482834 current_received_ts = 77.482430 current_seq = 37 count = 33 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.482834 last_received_ts = 77.482430 last_seq = 37 current_ts = 77.493942 current_received_ts = 77.493538 current_seq = 38 count = 34 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.493942 last_received_ts = 77.493538 last_seq = 38 current_ts = 77.505043 current_received_ts = 77.504646 current_seq = 39 count = 35 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 3us (kms_flip:2348) DEBUG: name = flip last_ts = 77.505043 last_received_ts = 77.504646 last_seq = 39 current_ts = 77.516144 current_received_ts = 77.515755 current_seq = 40 count = 36 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.516144 last_received_ts = 77.515755 last_seq = 40 current_ts = 77.527260 current_received_ts = 77.526855 current_seq = 41 count = 37 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.527260 last_received_ts = 77.526855 last_seq = 41 current_ts = 77.538361 current_received_ts = 77.538063 current_seq = 42 count = 38 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 9us (kms_flip:2348) DEBUG: name = flip last_ts = 77.538361 last_received_ts = 77.538063 last_seq = 42 current_ts = 77.549469 current_received_ts = 77.549065 current_seq = 43 count = 39 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 8us (kms_flip:2348) DEBUG: name = flip last_ts = 77.549469 last_received_ts = 77.549065 last_seq = 43 current_ts = 77.560570 current_received_ts = 77.560165 current_seq = 44 count = 40 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 6us (kms_flip:2348) DEBUG: name = flip last_ts = 77.560570 last_received_ts = 77.560165 last_seq = 44 current_ts = 77.571671 current_received_ts = 77.571358 current_seq = 45 count = 41 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 5us (kms_flip:2348) DEBUG: name = flip last_ts = 77.571671 last_received_ts = 77.571358 last_seq = 45 current_ts = 77.582787 current_received_ts = 77.582458 current_seq = 46 count = 42 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.582787 last_received_ts = 77.582458 last_seq = 46 current_ts = 77.593887 current_received_ts = 77.593559 current_seq = 47 count = 43 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.593887 last_received_ts = 77.593559 last_seq = 47 current_ts = 77.604988 current_received_ts = 77.604660 current_seq = 48 count = 44 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.604988 last_received_ts = 77.604660 last_seq = 48 current_ts = 77.616096 current_received_ts = 77.615768 current_seq = 49 count = 45 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.616096 last_received_ts = 77.615768 last_seq = 49 current_ts = 77.627205 current_received_ts = 77.626900 current_seq = 50 count = 46 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.627205 last_received_ts = 77.626900 last_seq = 50 current_ts = 77.638306 current_received_ts = 77.637978 current_seq = 51 count = 47 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.638306 last_received_ts = 77.637978 last_seq = 51 current_ts = 77.649414 current_received_ts = 77.649086 current_seq = 52 count = 48 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.649414 last_received_ts = 77.649086 last_seq = 52 current_ts = 77.660522 current_received_ts = 77.660263 current_seq = 53 count = 49 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.660522 last_received_ts = 77.660263 last_seq = 53 current_ts = 77.671623 current_received_ts = 77.671234 current_seq = 54 count = 50 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.671623 last_received_ts = 77.671234 last_seq = 54 current_ts = 77.682732 current_received_ts = 77.682335 current_seq = 55 count = 51 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.682732 last_received_ts = 77.682335 last_seq = 55 current_ts = 77.693840 current_received_ts = 77.693436 current_seq = 56 count = 52 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.693840 last_received_ts = 77.693436 last_seq = 56 current_ts = 77.704941 current_received_ts = 77.704536 current_seq = 57 count = 53 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 5us (kms_flip:2348) DEBUG: name = flip last_ts = 77.704941 last_received_ts = 77.704536 last_seq = 57 current_ts = 77.716049 current_received_ts = 77.715645 current_seq = 58 count = 54 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.716049 last_received_ts = 77.715645 last_seq = 58 current_ts = 77.727150 current_received_ts = 77.726761 current_seq = 59 count = 55 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 5us (kms_flip:2348) DEBUG: name = flip last_ts = 77.727150 last_received_ts = 77.726761 last_seq = 59 current_ts = 77.738258 current_received_ts = 77.737854 current_seq = 60 count = 56 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.738258 last_received_ts = 77.737854 last_seq = 60 current_ts = 77.749367 current_received_ts = 77.748962 current_seq = 61 count = 57 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 5us (kms_flip:2348) DEBUG: name = flip last_ts = 77.749367 last_received_ts = 77.748962 last_seq = 61 current_ts = 77.760468 current_received_ts = 77.760063 current_seq = 62 count = 58 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.760468 last_received_ts = 77.760063 last_seq = 62 current_ts = 77.771576 current_received_ts = 77.771172 current_seq = 63 count = 59 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.771576 last_received_ts = 77.771172 last_seq = 63 current_ts = 77.782677 current_received_ts = 77.782280 current_seq = 64 count = 60 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.782677 last_received_ts = 77.782280 last_seq = 64 current_ts = 77.793785 current_received_ts = 77.793381 current_seq = 65 count = 61 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.793785 last_received_ts = 77.793381 last_seq = 65 current_ts = 77.804893 current_received_ts = 77.804489 current_seq = 66 count = 62 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.804893 last_received_ts = 77.804489 last_seq = 66 current_ts = 77.815994 current_received_ts = 77.815590 current_seq = 67 count = 63 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.815994 last_received_ts = 77.815590 last_seq = 67 current_ts = 77.827103 current_received_ts = 77.826698 current_seq = 68 count = 64 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 4us (kms_flip:2348) DEBUG: name = flip last_ts = 77.827103 last_received_ts = 77.826698 last_seq = 68 current_ts = 77.838203 current_received_ts = 77.837807 current_seq = 69 count = 65 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 5us (kms_flip:2348) DEBUG: name = flip last_ts = 77.838203 last_received_ts = 77.837807 last_seq = 69 current_ts = 77.849312 current_received_ts = 77.848915 current_seq = 70 count = 66 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 5us (kms_flip:2348) DEBUG: name = flip last_ts = 77.849312 last_received_ts = 77.848915 last_seq = 70 current_ts = 77.860420 current_received_ts = 77.860031 current_seq = 71 count = 67 seq_step = 1 (kms_flip:2348) DEBUG: Vblank took 511us (kms_flip:2348) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2348) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2348) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2348) igt_core-INFO: Stack trace: (kms_flip:2348) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2348) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:2348) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:2348) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() (kms_flip:2348) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:2348) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2348) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2348) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest C-eDP1: FAIL (1.870s)
Dmesg	<6> [76.272712] [IGT] kms_flip: starting dynamic subtest C-eDP1 <7> [76.273398] i915 0000:00:02.0: [drm:i915_dpt_create [i915]] Allocating dpt from smem <7> [76.273879] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:566] <7> [76.274124] i915 0000:00:02.0: [drm:i915_dpt_create [i915]] Allocating dpt from smem <7> [76.274478] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:568] <7> [76.277842] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [76.278504] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [76.296758] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [76.297015] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [76.304907] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [76.305225] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [76.325716] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [76.325986] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [76.332723] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [76.332920] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B] <7> [76.332982] 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> [76.333168] 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> [76.333315] 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> [76.333463] 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> [76.333609] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in dp_m_n (expected tu 64 data 7483046/8388608 link 498869/524288, found tu 0, data 0/0 link 0/0) <7> [76.333752] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [76.333896] 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> [76.334036] 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 2880, found 0) <7> [76.334183] 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 3040, found 0) <7> [76.334327] 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 2880, found 0) <7> [76.334463] 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 3040, found 0) <7> [76.334598] 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 2928, found 0) <7> [76.334734] 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 2960, found 0) <7> [76.334879] 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 1800, found 0) <7> [76.335015] 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 1801, found 0) <7> [76.335157] 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 1803, found 0) <7> [76.335297] 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 1809, found 0) <7> [76.335438] 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 1878, found 0) <7> [76.335574] 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 1878, found 0) <7> [76.335710] 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 2880, found 0) <7> [76.335846] 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 3040, found 0) <7> [76.335980] 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 2880, found 0) <7> [76.336119] 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 3040, found 0) <7> [76.336254] 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 2928, found 0) <7> [76.336389] 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 2960, found 0) <7> [76.336523] 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 1800, found 0) <7> [76.336655] 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 1801, found 0) <7> [76.336787] 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 1803, found 0) <7> [76.336918] 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 1809, found 0) <7> [76.337049] 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 1878, found 0) <7> [76.337268] 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 1878, found 0) <7> [76.337406] 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> [76.337544] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [76.337678] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [76.337812] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in enhanced_framing (expected yes, found no) <7> [76.337946] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [76.338079] 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 513820, found 0) <7> [76.338225] 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 513820, found 0) <7> [76.338362] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in port_clock (expected 540000, found 0) <7> [76.338499] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in set_context_latency (expected 1, found 0) <7> [76.338632] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:269:pipe B] fastset requirement not met, forcing full modeset <7> [76.338765] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:269:pipe B] releasing DPLL 0 <7> [76.338930] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [76.339067] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:269:pipe B] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x2 -> 0x0 <7> [76.339232] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:263:cursor B] ddb (4001 - 4096) -> ( 0 - 0), size 95 -> 0 <7> [76.339367] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:269:pipe B] min cdclk: 256910 kHz -> 0 kHz <7> [76.339510] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Can change cdclk via squashing <7> [76.339651] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 172800 kHz, actual 172800 kHz <7> [76.339789] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0 <7> [76.339956] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:269:pipe B] enable: no [modeset] <7> [76.340096] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 1B] fb: [NOFB], visible: no <7> [76.340250] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:183:plane 2B] fb: [NOFB], visible: no <7> [76.340388] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:213:plane 3B] fb: [NOFB], visible: no <7> [76.340525] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:243:plane 4B] fb: [NOFB], visible: no <7> [76.340659] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:253:plane 5B] fb: [NOFB], visible: no <7> [76.340793] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:263:cursor B] fb: [NOFB], visible: no <7> [76.341123] i915 0000:00:02.0: [drm:intel_edp_backlight_off [i915]] <7> [76.549370] i915 0000:00:02.0: [drm:intel_backlight_set_pwm_level [i915]] [CONNECTOR:508:eDP-1] set backlight PWM = 0 <7> [76.550096] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B <7> [76.562536] i915 0000:00:02.0: [drm:intel_pps_off_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 turn panel power off <7> [76.562739] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x00000089, pins 0x00000010, long 0x00000000 <7> [76.563026] i915 0000:00:02.0: [drm:intel_pps_off_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 wait for panel power off time <7> [76.563244] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:507:DDI A/PHY A] - short <7> [76.563562] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [76.614313] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete <7> [76.614850] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:269:pipe B] <7> [76.614885] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring short hpd on eDP [ENCODER:507:DDI A/PHY A] <7> [76.615607] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x0000008a, pins 0x00000010, long 0x00000010 <7> [76.616193] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:507:DDI A/PHY A] - long <7> [76.616712] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [76.616781] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0 <7> [76.617313] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling AUX_A <7> [76.617266] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP [ENCODER:507:DDI A/PHY A] <7> [76.617743] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A] <7> [76.618066] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:516:DDI B/PHY B] <7> [76.618384] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:518:DP-MST A] <7> [76.618774] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DP-MST B] <7> [76.619061] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DP-MST C] <7> [76.619269] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:521:DP-MST D] <7> [76.619459] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:529:DDI TC1/PHY TC1] <7> [76.619677] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:531:DP-MST A] <7> [76.619808] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:532:DP-MST B] <7> [76.619947] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:533:DP-MST C] <7> [76.620078] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:534:DP-MST D] <7> [76.620210] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DDI TC2/PHY TC2] <7> [76.620359] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST A] <7> [76.620548] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:541:DP-MST B] <7> [76.620692] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:542:DP-MST C] <7> [76.620817] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:543:DP-MST D] <7> [76.620938] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI TC3/PHY TC3] <7> [76.621059] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A] <7> [76.621180] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B] <7> [76.621340] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C] <7> [76.621525] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D] <7> [76.621673] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:556:DDI TC4/PHY TC4] <7> [76.621819] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:558:DP-MST A] <7> [76.621946] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:559:DP-MST B] <7> [76.622070] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:560:DP-MST C] <7> [76.622194] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:561:DP-MST D] <7> [76.622328] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:508:eDP-1] <7> [76.622522] i915 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [i915]] Updating dbuf ratio to 2 (mbus joined: no) <7> [76.622676] i915 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [i915]] Changing mbus joined: yes -> no (pipe: ) <7> [76.622812] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1 <7> [76.623056] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_B <7> [76.623203] i915 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [i915]] DSS clock gating disabled for pipe_mask=0x2 (CLKGATE_DIS_DSSDSC=0xaa000000) <7> [76.623404] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_2 <7> [76.623576] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:269:pipe B] <7> [76.623759] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Post changing CDCLK to 172800 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [76.623936] i915 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=432 <7> [76.624240] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C] <7> [76.624379] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D] <7> [76.624487] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C] <7> [76.624511] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:508:eDP-1] <7> [76.624562] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:508:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [76.624709] i915 0000:00:02.0: [drm:intel_dp_compute_config_limits [i915]] [ENCODER:507:DDI A/PHY A][CRTC:387:pipe C] DP link limits: pixel clock 513820 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000 <7> [76.624834] i915 0000:00:02.0: [drm:intel_dp_compute_output_format [i915]] DP lane count 4 clock 540000 bpp input 30 compressed 0.0000 HDR no link rate required 1926825 available 2160000 <7> [76.624957] i915 0000:00:02.0: [drm:intel_psr_compute_config [i915]] PSR2 not supported in transcoder C <7> [76.625089] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [76.625228] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:507:DDI A/PHY A] [CRTC:387:pipe C] <7> [76.625370] 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> [76.625511] 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> [76.625651] 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> [76.625791] 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> [76.625930] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 7483046/8388608 link 498869/524288) <7> [76.626070] 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 0x00000100) <7> [76.626210] 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> [76.626364] 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 2880) <7> [76.626504] 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 3040) <7> [76.626645] 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 2880) <7> [76.626784] 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 3040) <7> [76.626919] 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 2928) <7> [76.627055] 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 2960) <7> [76.627190] 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 1800) <7> [76.627334] 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 1801) <7> [76.627469] 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 1803) <7> [76.627604] 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 1809) <7> [76.627735] 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 1878) <7> [76.627866] 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 1878) <7> [76.628000] 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 2880) <7> [76.628132] 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 3040) <7> [76.628264] 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 2880) <7> [76.628411] 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 3040) <7> [76.628544] 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 2928) <7> [76.628677] 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 2960) <7> [76.628811] 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 1800) <7> [76.628944] 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 1801) <7> [76.629076] 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 1803) <7> [76.629205] 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 1809) <7> [76.629347] 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 1878) <7> [76.629484] 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 1878) <7> [76.629619] 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> [76.629753] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [76.629889] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [76.630025] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in enhanced_framing (expected no, found yes) <7> [76.630162] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in dpll_hw_state <7> [76.630301] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [76.630438] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] cx0pll_hw_state: lane_count: 0, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [76.630576] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] c20pll_hw_state: <7> [76.630712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] tx[0] = 0x0000, tx[1] = 0x0000, tx[2] = 0x0000 <7> [76.630849] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] cmn[0] = 0x0000, cmn[1] = 0x0000, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [76.630985] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[0] = 0x0000 <7> [76.631117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[1] = 0x0000 <7> [76.631250] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[2] = 0x0000 <7> [76.631395] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[3] = 0x0000 <7> [76.631527] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[4] = 0x0000 <7> [76.631658] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[5] = 0x0000 <7> [76.631791] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[6] = 0x0000 <7> [76.631924] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[7] = 0x0000 <7> [76.632056] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[8] = 0x0000 <7> [76.632187] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[9] = 0x0000 <7> [76.632321] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mpllb[10] = 0x0000 <7> [76.632454] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00 <7> [76.632584] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [76.632715] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no <7> [76.632847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] c10pll_hw_state: fracen: yes, <7> [76.632982] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] quot: 40960, rem: 0, den: 1, <7> [76.633116] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] multiplier: 140, tx_clk_div: 0. <7> [76.633250] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] c10pll_rawhw_state: <7> [76.633390] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] tx: 0x10, cmn: 0x21 <7> [76.633522] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[0] = 0xf4, pll[1] = 0x0, pll[2] = 0xf8, pll[3] = 0x0 <7> [76.633656] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [76.633790] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [76.633922] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[12] = 0xa0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x0 <7> [76.634053] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[16] = 0x84, pll[17] = 0x4f, pll[18] = 0xe5, pll[19] = 0x23 <7> [76.634184] 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 30) <7> [76.634321] 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 513820) <7> [76.634454] 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 513820) <7> [76.634588] 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 540000) <7> [76.634723] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in set_context_latency (expected 0, found 1) <7> [76.634856] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe C] fastset requirement not met, forcing full modeset <7> [76.635013] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no <7> [76.635144] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4 <7> [76.635307] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:271:plane 1C] ddb ( 0 - 0) -> ( 0 - 1953), size 0 -> 1953 <7> [76.635435] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor C] ddb ( 0 - 0) -> (1953 - 2048), size 0 -> 95 <7> [76.635561] 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> [76.635686] 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 -> 4, 16, 16, 19, 19, 28, 0, 0, 0, 4, 0 <7> [76.635811] 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 -> 92, 365, 365, 434, 434, 638, 0, 0, 197, 92, 197 <7> [76.635939] 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 -> 183, 456, 456, 547, 547, 729, 0, 0, 198, 183, 198 <7> [76.636079] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:387:pipe C] data rate 2055280 num active planes 1 <7> [76.636219] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 28913 required 2159 qgv_peak_bw: 51200 <7> [76.636408] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 1: max bw 33901 required 2159 qgv_peak_bw: 51200 <7> [76.636542] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 2: max bw 38000 required 2159 qgv_peak_bw: 51200 <7> [76.636676] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 3: max bw 38000 required 2159 qgv_peak_bw: 51200 <7> [76.636809] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] Matching peaks QGV bw: 51200 for required data rate: 2159 <7> [76.636957] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe C] min cdclk: 0 kHz -> 256910 kHz <7> [76.637110] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Can change cdclk via squashing <7> [76.637247] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 307200 kHz, actual 307200 kHz <7> [76.637392] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0 <7> [76.637546] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:387:pipe C] allocated DPLL 0 <7> [76.637686] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:387:pipe C] reserving DPLL 0 <7> [76.637830] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe C] enable: yes [modeset] <7> [76.637971] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [76.638110] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: C, pipe bpp: 30, dithering: 0 <7> [76.638245] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [76.638389] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [76.638525] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [76.638671] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [76.638814] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dp m_n: lanes: 4; data_m: 7483046, data_n: 8388608, link_m: 498869, link_n: 524288, tu: 64 <7> [76.638957] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0 <7> [76.639100] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fec: disabled, enhanced framing: enabled <7> [76.639243] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sdp split: disabled <7> [76.639391] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] psr: enabled, selective update: disabled, panel replay: disabled, selective fetch: disabled <7> [76.639526] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] minimum hblank: 0 <7> [76.639658] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [76.639790] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] DP SDP: VSC, revision 2, length 8 <7> [76.639927] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pixelformat: RGB <7> [76.640063] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] colorimetry: sRGB <7> [76.640197] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] bpc: 0 <7> [76.640335] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dynamic range: VESA range <7> [76.640467] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] content type: Not defined <7> [76.640600] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1 <7> [76.640735] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 1 <7> [76.640869] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1878, vmax: 1878, flipline: 1878, pipeline full: 0, guardband: 76 vsync start: 75, vsync end: 69 <7> [76.641003] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1878, vmax vtotal: 1878 <7> [76.641135] 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> [76.641267] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa <7> [76.641413] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa <7> [76.641545] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=513820, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1801-1878 vs=1803-1809 vt=1878, flags=0xa <7> [76.641678] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x40 0xa <7> [76.641812] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=513820, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1801-1878 vs=1803-1809 vt=1878, flags=0xa <7> [76.641945] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 540000, pixel rate 513820, min cdclk 256910, min voltage level 0 <7> [76.642076] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 48, ips linetime: 0 <7> [76.642207] 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> [76.642352] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 2880x1800+0+0 <7> [76.642483] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [76.642381] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off <7> [76.642617] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [76.642753] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [76.642886] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no <7> [76.642819] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6 <7> [76.643018] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] c10pll_hw_state: fracen: yes, <7> [76.643149] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] quot: 40960, rem: 0, den: 1, <7> [76.643160] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02 <7> [76.643281] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] multiplier: 140, tx_clk_div: 0. <7> [76.643429] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] c10pll_rawhw_state: <7> [76.643561] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] tx: 0x10, cmn: 0x21 <7> [76.643694] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[0] = 0xf4, pll[1] = 0x0, pll[2] = 0xf8, pll[3] = 0x0 <7> [76.643828] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [76.643961] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [76.644093] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[12] = 0xa0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x0 <7> [76.644225] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[16] = 0x84, pll[17] = 0x4f, pll[18] = 0xe5, pll[19] = 0x23 <7> [76.644373] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [76.644506] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [76.644639] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [76.644770] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [76.644902] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [76.645037] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [76.645173] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [76.645312] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [76.645447] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [76.645580] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [76.645715] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [76.645849] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [76.645981] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [FB:566] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [76.646114] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [76.646248] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [76.646394] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2C] fb: [NOFB], visible: no <7> [76.646528] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3C] fb: [NOFB], visible: no <7> [76.646658] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4C] fb: [NOFB], visible: no <7> [76.646789] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5C] fb: [NOFB], visible: no <7> [76.646919] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor C] fb: [NOFB], visible: no <7> [76.649778] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off <7> [76.650117] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 02 to 00 <7> [76.650351] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_2 <7> [76.650518] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_C <7> [76.650702] i915 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [i915]] DSS clock gating enabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0x8a000000) <7> [76.650866] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 307200 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [76.651041] i915 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=768 <7> [76.651179] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A] <7> [76.651335] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:516:DDI B/PHY B] <7> [76.651475] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:518:DP-MST A] <7> [76.651612] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DP-MST B] <7> [76.651747] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DP-MST C] <7> [76.651882] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:521:DP-MST D] <7> [76.652017] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:529:DDI TC1/PHY TC1] <7> [76.652149] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:531:DP-MST A] <7> [76.652282] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:532:DP-MST B] <7> [76.652428] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:533:DP-MST C] <7> [76.652564] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:534:DP-MST D] <7> [76.652702] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DDI TC2/PHY TC2] <7> [76.652837] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST A] <7> [76.652967] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:541:DP-MST B] <7> [76.653095] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:542:DP-MST C] <7> [76.653221] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:543:DP-MST D] <7> [76.653358] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI TC3/PHY TC3] <7> [76.653491] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A] <7> [76.653619] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B] <7> [76.653742] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C] <7> [76.653867] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D] <7> [76.653990] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:556:DDI TC4/PHY TC4] <7> [76.654115] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:558:DP-MST A] <7> [76.654240] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:559:DP-MST B] <7> [76.654378] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:560:DP-MST C] <7> [76.654511] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:561:DP-MST D] <7> [76.654672] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xd <7> [76.654899] i915 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [i915]] Updating dbuf ratio to 2 (mbus joined: no) <7> [76.655101] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling AUX_A <7> [76.656430] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:387:pipe C] <7> [76.656589] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0 <7> [76.658545] i915 0000:00:02.0: [drm:intel_pps_on_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 turn panel power on <7> [76.658697] i915 0000:00:02.0: [drm:wait_panel_power_cycle [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 wait for panel power cycle (457 ms remaining) <7> [77.117725] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [77.127635] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete <7> [77.128182] i915 0000:00:02.0: [drm:intel_pps_on_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 wait for panel power on <7> [77.128724] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [77.160095] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x0000008a, pins 0x00000010, long 0x00000010 <7> [77.160441] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:507:DDI A/PHY A] - long <7> [77.160778] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [77.161137] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP [ENCODER:507:DDI A/PHY A] <7> [77.334077] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete <7> [77.334798] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 turning VDD on <7> [77.335355] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [77.338665] i915 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 14 c4 41 00 00 01 c0 02 00 00 00 00 0b 80 <7> [77.340253] i915 0000:00:02.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [77.340914] i915 0000:00:02.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 07 <7> [77.341910] i915 0000:00:02.0: [drm:intel_dp_set_signal_levels [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [77.342997] i915 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [77.343906] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Clock recovery OK <7> [77.344028] i915 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Using DP training pattern TPS3 <7> [77.345319] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [77.345444] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Link Training passed at link rate = 540000, lane count = 4 <7> [77.346066] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe C <7> [77.346344] i915 0000:00:02.0: [drm:intel_edp_backlight_on [i915]] <7> [77.346467] i915 0000:00:02.0: [drm:intel_backlight_enable [i915]] pipe C <7> [77.346666] i915 0000:00:02.0: [drm:intel_backlight_set_pwm_level [i915]] [CONNECTOR:508:eDP-1] set backlight PWM = 13892 <7> [77.357521] i915 0000:00:02.0: [drm:intel_psr_post_plane_update [i915]] Enabling PSR1 <7> [77.358705] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:508:eDP-1] <7> [77.358925] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe C] <6> [78.142987] [IGT] kms_flip: finished subtest C-eDP1, FAIL

Detail

Value

Duration

1.87 seconds

Hostname

shard-mtlp-1

Igt-Version

IGT-Version: 2.4-gfa229a9c1 (x86_64) (Linux: 7.0.0-CI_DRM_18366-gd431883e767c+ x86_64)

Out

Starting dynamic subtest: C-eDP1
  2880x1800: 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa 
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-eDP1: FAIL (1.870s)

Err

Starting dynamic subtest: C-eDP1
(kms_flip:2348) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2348) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2348) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest C-eDP1 failed.
**** DEBUG ****
(kms_flip:2348) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0)
(kms_flip:2348) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2348) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2348) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=11520)
(kms_flip:2348) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2348) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0)
(kms_flip:2348) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2348) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2348) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=11520)
(kms_flip:2348) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd)
(kms_flip:2348) intel_allocator_reloc-DEBUG: Using reloc allocator
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd)
(kms_flip:2348) intel_allocator_reloc-DEBUG: Using reloc allocator
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd)
(kms_flip:2348) intel_allocator_reloc-DEBUG: Using reloc allocator
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd)
(kms_flip:2348) intel_allocator_reloc-DEBUG: Using reloc allocator
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2348) igt_kms-INFO:   2880x1800: 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa 
(kms_flip:2348) DEBUG: No stale events found
(kms_flip:2348) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2348) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2348) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 77.116379
current_received_ts = 77.115982
current_seq = 4
count = 0
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 10us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.116379
last_received_ts = 77.115982
last_seq = 4
current_ts = 77.127487
current_received_ts = 77.127075
current_seq = 5
count = 1
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 2us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.127487
last_received_ts = 77.127075
last_seq = 5
current_ts = 77.138588
current_received_ts = 77.138184
current_seq = 6
count = 2
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.138588
last_received_ts = 77.138184
last_seq = 6
current_ts = 77.149689
current_received_ts = 77.149292
current_seq = 7
count = 3
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.149689
last_received_ts = 77.149292
last_seq = 7
current_ts = 77.160797
current_received_ts = 77.160400
current_seq = 8
count = 4
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 6us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.160797
last_received_ts = 77.160400
last_seq = 8
current_ts = 77.171906
current_received_ts = 77.171501
current_seq = 9
count = 5
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.171906
last_received_ts = 77.171501
last_seq = 9
current_ts = 77.183006
current_received_ts = 77.182617
current_seq = 10
count = 6
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.183006
last_received_ts = 77.182617
last_seq = 10
current_ts = 77.194115
current_received_ts = 77.193710
current_seq = 11
count = 7
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.194115
last_received_ts = 77.193710
last_seq = 11
current_ts = 77.205215
current_received_ts = 77.204819
current_seq = 12
count = 8
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.205215
last_received_ts = 77.204819
last_seq = 12
current_ts = 77.216316
current_received_ts = 77.215919
current_seq = 13
count = 9
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.216316
last_received_ts = 77.215919
last_seq = 13
current_ts = 77.227425
current_received_ts = 77.227028
current_seq = 14
count = 10
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.227425
last_received_ts = 77.227028
last_seq = 14
current_ts = 77.238525
current_received_ts = 77.238121
current_seq = 15
count = 11
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.238525
last_received_ts = 77.238121
last_seq = 15
current_ts = 77.249634
current_received_ts = 77.249237
current_seq = 16
count = 12
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 5us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.249634
last_received_ts = 77.249237
last_seq = 16
current_ts = 77.260735
current_received_ts = 77.260330
current_seq = 17
count = 13
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.260735
last_received_ts = 77.260330
last_seq = 17
current_ts = 77.271843
current_received_ts = 77.271446
current_seq = 18
count = 14
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.271843
last_received_ts = 77.271446
last_seq = 18
current_ts = 77.282944
current_received_ts = 77.282539
current_seq = 19
count = 15
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.282944
last_received_ts = 77.282539
last_seq = 19
current_ts = 77.294052
current_received_ts = 77.293648
current_seq = 20
count = 16
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.294052
last_received_ts = 77.293648
last_seq = 20
current_ts = 77.305161
current_received_ts = 77.304756
current_seq = 21
count = 17
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.305161
last_received_ts = 77.304756
last_seq = 21
current_ts = 77.316261
current_received_ts = 77.315865
current_seq = 22
count = 18
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.316261
last_received_ts = 77.315865
last_seq = 22
current_ts = 77.327370
current_received_ts = 77.326965
current_seq = 23
count = 19
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.327370
last_received_ts = 77.326965
last_seq = 23
current_ts = 77.338470
current_received_ts = 77.338074
current_seq = 24
count = 20
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.338470
last_received_ts = 77.338074
last_seq = 24
current_ts = 77.349571
current_received_ts = 77.349167
current_seq = 25
count = 21
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.349571
last_received_ts = 77.349167
last_seq = 25
current_ts = 77.360680
current_received_ts = 77.360275
current_seq = 26
count = 22
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.360680
last_received_ts = 77.360275
last_seq = 26
current_ts = 77.371780
current_received_ts = 77.371384
current_seq = 27
count = 23
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.371780
last_received_ts = 77.371384
last_seq = 27
current_ts = 77.382889
current_received_ts = 77.382484
current_seq = 28
count = 24
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.382889
last_received_ts = 77.382484
last_seq = 28
current_ts = 77.393997
current_received_ts = 77.393593
current_seq = 29
count = 25
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.393997
last_received_ts = 77.393593
last_seq = 29
current_ts = 77.405098
current_received_ts = 77.404694
current_seq = 30
count = 26
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 5us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.405098
last_received_ts = 77.404694
last_seq = 30
current_ts = 77.416199
current_received_ts = 77.415794
current_seq = 31
count = 27
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.416199
last_received_ts = 77.415794
last_seq = 31
current_ts = 77.427307
current_received_ts = 77.426910
current_seq = 32
count = 28
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.427307
last_received_ts = 77.426910
last_seq = 32
current_ts = 77.438416
current_received_ts = 77.438019
current_seq = 33
count = 29
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.438416
last_received_ts = 77.438019
last_seq = 33
current_ts = 77.449516
current_received_ts = 77.449112
current_seq = 34
count = 30
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.449516
last_received_ts = 77.449112
last_seq = 34
current_ts = 77.460625
current_received_ts = 77.460220
current_seq = 35
count = 31
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.460625
last_received_ts = 77.460220
last_seq = 35
current_ts = 77.471725
current_received_ts = 77.471329
current_seq = 36
count = 32
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.471725
last_received_ts = 77.471329
last_seq = 36
current_ts = 77.482834
current_received_ts = 77.482430
current_seq = 37
count = 33
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.482834
last_received_ts = 77.482430
last_seq = 37
current_ts = 77.493942
current_received_ts = 77.493538
current_seq = 38
count = 34
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.493942
last_received_ts = 77.493538
last_seq = 38
current_ts = 77.505043
current_received_ts = 77.504646
current_seq = 39
count = 35
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 3us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.505043
last_received_ts = 77.504646
last_seq = 39
current_ts = 77.516144
current_received_ts = 77.515755
current_seq = 40
count = 36
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.516144
last_received_ts = 77.515755
last_seq = 40
current_ts = 77.527260
current_received_ts = 77.526855
current_seq = 41
count = 37
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.527260
last_received_ts = 77.526855
last_seq = 41
current_ts = 77.538361
current_received_ts = 77.538063
current_seq = 42
count = 38
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 9us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.538361
last_received_ts = 77.538063
last_seq = 42
current_ts = 77.549469
current_received_ts = 77.549065
current_seq = 43
count = 39
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 8us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.549469
last_received_ts = 77.549065
last_seq = 43
current_ts = 77.560570
current_received_ts = 77.560165
current_seq = 44
count = 40
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 6us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.560570
last_received_ts = 77.560165
last_seq = 44
current_ts = 77.571671
current_received_ts = 77.571358
current_seq = 45
count = 41
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 5us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.571671
last_received_ts = 77.571358
last_seq = 45
current_ts = 77.582787
current_received_ts = 77.582458
current_seq = 46
count = 42
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.582787
last_received_ts = 77.582458
last_seq = 46
current_ts = 77.593887
current_received_ts = 77.593559
current_seq = 47
count = 43
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.593887
last_received_ts = 77.593559
last_seq = 47
current_ts = 77.604988
current_received_ts = 77.604660
current_seq = 48
count = 44
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.604988
last_received_ts = 77.604660
last_seq = 48
current_ts = 77.616096
current_received_ts = 77.615768
current_seq = 49
count = 45
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.616096
last_received_ts = 77.615768
last_seq = 49
current_ts = 77.627205
current_received_ts = 77.626900
current_seq = 50
count = 46
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.627205
last_received_ts = 77.626900
last_seq = 50
current_ts = 77.638306
current_received_ts = 77.637978
current_seq = 51
count = 47
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.638306
last_received_ts = 77.637978
last_seq = 51
current_ts = 77.649414
current_received_ts = 77.649086
current_seq = 52
count = 48
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.649414
last_received_ts = 77.649086
last_seq = 52
current_ts = 77.660522
current_received_ts = 77.660263
current_seq = 53
count = 49
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.660522
last_received_ts = 77.660263
last_seq = 53
current_ts = 77.671623
current_received_ts = 77.671234
current_seq = 54
count = 50
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.671623
last_received_ts = 77.671234
last_seq = 54
current_ts = 77.682732
current_received_ts = 77.682335
current_seq = 55
count = 51
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.682732
last_received_ts = 77.682335
last_seq = 55
current_ts = 77.693840
current_received_ts = 77.693436
current_seq = 56
count = 52
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.693840
last_received_ts = 77.693436
last_seq = 56
current_ts = 77.704941
current_received_ts = 77.704536
current_seq = 57
count = 53
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 5us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.704941
last_received_ts = 77.704536
last_seq = 57
current_ts = 77.716049
current_received_ts = 77.715645
current_seq = 58
count = 54
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.716049
last_received_ts = 77.715645
last_seq = 58
current_ts = 77.727150
current_received_ts = 77.726761
current_seq = 59
count = 55
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 5us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.727150
last_received_ts = 77.726761
last_seq = 59
current_ts = 77.738258
current_received_ts = 77.737854
current_seq = 60
count = 56
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.738258
last_received_ts = 77.737854
last_seq = 60
current_ts = 77.749367
current_received_ts = 77.748962
current_seq = 61
count = 57
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 5us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.749367
last_received_ts = 77.748962
last_seq = 61
current_ts = 77.760468
current_received_ts = 77.760063
current_seq = 62
count = 58
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.760468
last_received_ts = 77.760063
last_seq = 62
current_ts = 77.771576
current_received_ts = 77.771172
current_seq = 63
count = 59
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.771576
last_received_ts = 77.771172
last_seq = 63
current_ts = 77.782677
current_received_ts = 77.782280
current_seq = 64
count = 60
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.782677
last_received_ts = 77.782280
last_seq = 64
current_ts = 77.793785
current_received_ts = 77.793381
current_seq = 65
count = 61
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.793785
last_received_ts = 77.793381
last_seq = 65
current_ts = 77.804893
current_received_ts = 77.804489
current_seq = 66
count = 62
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.804893
last_received_ts = 77.804489
last_seq = 66
current_ts = 77.815994
current_received_ts = 77.815590
current_seq = 67
count = 63
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.815994
last_received_ts = 77.815590
last_seq = 67
current_ts = 77.827103
current_received_ts = 77.826698
current_seq = 68
count = 64
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 4us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.827103
last_received_ts = 77.826698
last_seq = 68
current_ts = 77.838203
current_received_ts = 77.837807
current_seq = 69
count = 65
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 5us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.838203
last_received_ts = 77.837807
last_seq = 69
current_ts = 77.849312
current_received_ts = 77.848915
current_seq = 70
count = 66
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 5us
(kms_flip:2348) DEBUG: name = flip
last_ts = 77.849312
last_received_ts = 77.848915
last_seq = 70
current_ts = 77.860420
current_received_ts = 77.860031
current_seq = 71
count = 67
seq_step = 1
(kms_flip:2348) DEBUG: Vblank took 511us
(kms_flip:2348) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2348) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2348) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2348) igt_core-INFO: Stack trace:
(kms_flip:2348) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2348) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2348) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2348) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2348) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2348) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2348) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2348) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-eDP1: FAIL (1.870s)

Dmesg

<6> [76.272712] [IGT] kms_flip: starting dynamic subtest C-eDP1

<7> [76.273398] i915 0000:00:02.0: [drm:i915_dpt_create [i915]] Allocating dpt from smem

<7> [76.273879] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:566]

<7> [76.274124] i915 0000:00:02.0: [drm:i915_dpt_create [i915]] Allocating dpt from smem

<7> [76.274478] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:568]

<7> [76.277842] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [76.278504] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [76.296758] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [76.297015] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [76.304907] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [76.305225] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [76.325716] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [76.325986] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

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

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

<7> [76.332982] 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> [76.333168] 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> [76.333315] 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> [76.333463] 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> [76.333609] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in dp_m_n (expected tu 64 data 7483046/8388608 link 498869/524288, found tu 0, data 0/0 link 0/0)

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

<7> [76.333896] 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> [76.334036] 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 2880, found 0)

<7> [76.334183] 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 3040, found 0)

<7> [76.334327] 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 2880, found 0)

<7> [76.334463] 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 3040, found 0)

<7> [76.334598] 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 2928, found 0)

<7> [76.334734] 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 2960, found 0)

<7> [76.334879] 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 1800, found 0)

<7> [76.335015] 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 1801, found 0)

<7> [76.335157] 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 1803, found 0)

<7> [76.335297] 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 1809, found 0)

<7> [76.335438] 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 1878, found 0)

<7> [76.335574] 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 1878, found 0)

<7> [76.335710] 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 2880, found 0)

<7> [76.335846] 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 3040, found 0)

<7> [76.335980] 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 2880, found 0)

<7> [76.336119] 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 3040, found 0)

<7> [76.336254] 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 2928, found 0)

<7> [76.336389] 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 2960, found 0)

<7> [76.336523] 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 1800, found 0)

<7> [76.336655] 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 1801, found 0)

<7> [76.336787] 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 1803, found 0)

<7> [76.336918] 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 1809, found 0)

<7> [76.337049] 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 1878, found 0)

<7> [76.337268] 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 1878, found 0)

<7> [76.337406] 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> [76.337544] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:269:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)

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

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

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

<7> [76.338079] 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 513820, found 0)

<7> [76.338225] 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 513820, found 0)

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

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

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

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

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

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

<7> [76.339232] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:263:cursor B] ddb (4001 - 4096) -> ( 0 - 0), size 95 -> 0

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

<7> [76.339510] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Can change cdclk via squashing

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

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

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

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

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

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

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

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

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

<7> [76.341123] i915 0000:00:02.0: [drm:intel_edp_backlight_off [i915]]

<7> [76.549370] i915 0000:00:02.0: [drm:intel_backlight_set_pwm_level [i915]] [CONNECTOR:508:eDP-1] set backlight PWM = 0

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

<7> [76.562536] i915 0000:00:02.0: [drm:intel_pps_off_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 turn panel power off

<7> [76.562739] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x00000089, pins 0x00000010, long 0x00000000

<7> [76.563026] i915 0000:00:02.0: [drm:intel_pps_off_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 wait for panel power off time

<7> [76.563244] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:507:DDI A/PHY A] - short

<7> [76.563562] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060

<7> [76.614313] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete

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

<7> [76.614885] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring short hpd on eDP [ENCODER:507:DDI A/PHY A]

<7> [76.615607] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x0000008a, pins 0x00000010, long 0x00000010

<7> [76.616193] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:507:DDI A/PHY A] - long

<7> [76.616712] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 10

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

<7> [76.617313] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling AUX_A

<7> [76.617266] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP [ENCODER:507:DDI A/PHY A]

<7> [76.617743] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]

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

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

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

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

<7> [76.619269] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:521:DP-MST D]

<7> [76.619459] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:529:DDI TC1/PHY TC1]

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

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

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

<7> [76.620078] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:534:DP-MST D]

<7> [76.620210] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DDI TC2/PHY TC2]

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

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

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

<7> [76.620817] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:543:DP-MST D]

<7> [76.620938] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI TC3/PHY TC3]

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

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

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

<7> [76.621525] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]

<7> [76.621673] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:556:DDI TC4/PHY TC4]

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

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

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

<7> [76.622194] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:561:DP-MST D]

<7> [76.622328] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:508:eDP-1]

<7> [76.622522] i915 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [i915]] Updating dbuf ratio to 2 (mbus joined: no)

<7> [76.622676] i915 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [i915]] Changing mbus joined: yes -> no (pipe: *)

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

<7> [76.623056] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_B

<7> [76.623203] i915 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [i915]] DSS clock gating disabled for pipe_mask=0x2 (CLKGATE_DIS_DSSDSC=0xaa000000)

<7> [76.623404] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_2

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

<7> [76.623759] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Post changing CDCLK to 172800 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0

<7> [76.623936] i915 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=432

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

<7> [76.624379] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]

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

<7> [76.624511] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:508:eDP-1]

<7> [76.624562] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:508:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)

<7> [76.624709] i915 0000:00:02.0: [drm:intel_dp_compute_config_limits [i915]] [ENCODER:507:DDI A/PHY A][CRTC:387:pipe C] DP link limits: pixel clock 513820 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000

<7> [76.624834] i915 0000:00:02.0: [drm:intel_dp_compute_output_format [i915]] DP lane count 4 clock 540000 bpp input 30 compressed 0.0000 HDR no link rate required 1926825 available 2160000

<7> [76.624957] i915 0000:00:02.0: [drm:intel_psr_compute_config [i915]] PSR2 not supported in transcoder C

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

<7> [76.625228] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:507:DDI A/PHY A] [CRTC:387:pipe C]

<7> [76.625370] 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> [76.625511] 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> [76.625651] 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> [76.625791] 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> [76.625930] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 7483046/8388608 link 498869/524288)

<7> [76.626070] 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 0x00000100)

<7> [76.626210] 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> [76.626364] 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 2880)

<7> [76.626504] 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 3040)

<7> [76.626645] 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 2880)

<7> [76.626784] 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 3040)

<7> [76.626919] 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 2928)

<7> [76.627055] 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 2960)

<7> [76.627190] 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 1800)

<7> [76.627334] 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 1801)

<7> [76.627469] 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 1803)

<7> [76.627604] 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 1809)

<7> [76.627735] 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 1878)

<7> [76.627866] 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 1878)

<7> [76.628000] 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 2880)

<7> [76.628132] 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 3040)

<7> [76.628264] 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 2880)

<7> [76.628411] 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 3040)

<7> [76.628544] 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 2928)

<7> [76.628677] 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 2960)

<7> [76.628811] 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 1800)

<7> [76.628944] 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 1801)

<7> [76.629076] 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 1803)

<7> [76.629205] 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 1809)

<7> [76.629347] 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 1878)

<7> [76.629484] 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 1878)

<7> [76.629619] 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> [76.629753] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)

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

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

<7> [76.630162] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe C] fastset requirement not met in dpll_hw_state

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

<7> [76.630438] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] cx0pll_hw_state: lane_count: 0, ssc_enabled: no, use_c10: no, tbt_mode: no

<7> [76.630576] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] c20pll_hw_state:

<7> [76.630712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] tx[0] = 0x0000, tx[1] = 0x0000, tx[2] = 0x0000

<7> [76.630849] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] cmn[0] = 0x0000, cmn[1] = 0x0000, cmn[2] = 0x0000, cmn[3] = 0x0000

<7> [76.630985] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[0] = 0x0000

<7> [76.631117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[1] = 0x0000

<7> [76.631250] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[2] = 0x0000

<7> [76.631395] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[3] = 0x0000

<7> [76.631527] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[4] = 0x0000

<7> [76.631658] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[5] = 0x0000

<7> [76.631791] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[6] = 0x0000

<7> [76.631924] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[7] = 0x0000

<7> [76.632056] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[8] = 0x0000

<7> [76.632187] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mplla[9] = 0x0000

<7> [76.632321] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] mpllb[10] = 0x0000

<7> [76.632454] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00

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

<7> [76.632715] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no

<7> [76.632847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] c10pll_hw_state: fracen: yes,

<7> [76.632982] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] quot: 40960, rem: 0, den: 1,

<7> [76.633116] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] multiplier: 140, tx_clk_div: 0.

<7> [76.633250] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] c10pll_rawhw_state:

<7> [76.633390] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] tx: 0x10, cmn: 0x21

<7> [76.633522] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[0] = 0xf4, pll[1] = 0x0, pll[2] = 0xf8, pll[3] = 0x0

<7> [76.633656] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0

<7> [76.633790] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0

<7> [76.633922] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[12] = 0xa0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x0

<7> [76.634053] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] pll[16] = 0x84, pll[17] = 0x4f, pll[18] = 0xe5, pll[19] = 0x23

<7> [76.634184] 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 30)

<7> [76.634321] 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 513820)

<7> [76.634454] 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 513820)

<7> [76.634588] 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 540000)

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

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

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

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

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

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

<7> [76.635561] 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> [76.635686] 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 -> 4, 16, 16, 19, 19, 28, 0, 0, 0, 4, 0

<7> [76.635811] 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 -> 92, 365, 365, 434, 434, 638, 0, 0, 197, 92, 197

<7> [76.635939] 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 -> 183, 456, 456, 547, 547, 729, 0, 0, 198, 183, 198

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

<7> [76.636219] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 28913 required 2159 qgv_peak_bw: 51200

<7> [76.636408] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 1: max bw 33901 required 2159 qgv_peak_bw: 51200

<7> [76.636542] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 2: max bw 38000 required 2159 qgv_peak_bw: 51200

<7> [76.636676] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 3: max bw 38000 required 2159 qgv_peak_bw: 51200

<7> [76.636809] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] Matching peaks QGV bw: 51200 for required data rate: 2159

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

<7> [76.637110] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Can change cdclk via squashing

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

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

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

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

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

<7> [76.637971] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB

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

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

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

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

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

<7> [76.638814] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dp m_n: lanes: 4; data_m: 7483046, data_n: 8388608, link_m: 498869, link_n: 524288, tu: 64

<7> [76.638957] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0

<7> [76.639100] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fec: disabled, enhanced framing: enabled

<7> [76.639243] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sdp split: disabled

<7> [76.639391] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] psr: enabled, selective update: disabled, panel replay: disabled, selective fetch: disabled

<7> [76.639526] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] minimum hblank: 0

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

<7> [76.639790] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] DP SDP: VSC, revision 2, length 8

<7> [76.639927] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pixelformat: RGB

<7> [76.640063] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] colorimetry: sRGB

<7> [76.640197] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] bpc: 0

<7> [76.640335] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dynamic range: VESA range

<7> [76.640467] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] content type: Not defined

<7> [76.640600] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1

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

<7> [76.640869] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1878, vmax: 1878, flipline: 1878, pipeline full: 0, guardband: 76 vsync start: 75, vsync end: 69

<7> [76.641003] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1878, vmax vtotal: 1878

<7> [76.641135] 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> [76.641267] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa

<7> [76.641413] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x48 0xa

<7> [76.641545] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=513820, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1801-1878 vs=1803-1809 vt=1878, flags=0xa

<7> [76.641678] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "2880x1800": 90 513820 2880 2928 2960 3040 1800 1803 1809 1878 0x40 0xa

<7> [76.641812] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=513820, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1801-1878 vs=1803-1809 vt=1878, flags=0xa

<7> [76.641945] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 540000, pixel rate 513820, min cdclk 256910, min voltage level 0

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

<7> [76.642207] 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> [76.642352] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 2880x1800+0+0

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

<7> [76.642381] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off

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

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

<7> [76.642886] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no

<7> [76.642819] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6

<7> [76.643018] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] c10pll_hw_state: fracen: yes,

<7> [76.643149] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] quot: 40960, rem: 0, den: 1,

<7> [76.643160] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02

<7> [76.643281] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] multiplier: 140, tx_clk_div: 0.

<7> [76.643429] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] c10pll_rawhw_state:

<7> [76.643561] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] tx: 0x10, cmn: 0x21

<7> [76.643694] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[0] = 0xf4, pll[1] = 0x0, pll[2] = 0xf8, pll[3] = 0x0

<7> [76.643828] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0

<7> [76.643961] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0

<7> [76.644093] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[12] = 0xa0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x0

<7> [76.644225] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pll[16] = 0x84, pll[17] = 0x4f, pll[18] = 0xe5, pll[19] = 0x23

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

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

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

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

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

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

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

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

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

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

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

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

<7> [76.645981] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1C] fb: [FB:566] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes

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

<7> [76.646248] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0

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

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

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

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

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

<7> [76.649778] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off

<7> [76.650117] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 02 to 00

<7> [76.650351] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_2

<7> [76.650518] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_C

<7> [76.650702] i915 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [i915]] DSS clock gating enabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0x8a000000)

<7> [76.650866] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 307200 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0

<7> [76.651041] i915 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=768

<7> [76.651179] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]

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

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

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

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

<7> [76.651882] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:521:DP-MST D]

<7> [76.652017] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:529:DDI TC1/PHY TC1]

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

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

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

<7> [76.652564] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:534:DP-MST D]

<7> [76.652702] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DDI TC2/PHY TC2]

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

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

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

<7> [76.653221] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:543:DP-MST D]

<7> [76.653358] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI TC3/PHY TC3]

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

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

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

<7> [76.653867] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]

<7> [76.653990] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:556:DDI TC4/PHY TC4]

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

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

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

<7> [76.654511] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:561:DP-MST D]

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

<7> [76.654899] i915 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [i915]] Updating dbuf ratio to 2 (mbus joined: no)

<7> [76.655101] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling AUX_A

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

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

<7> [76.658545] i915 0000:00:02.0: [drm:intel_pps_on_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 turn panel power on

<7> [76.658697] i915 0000:00:02.0: [drm:wait_panel_power_cycle [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 wait for panel power cycle (457 ms remaining)

<7> [77.117725] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060

<7> [77.127635] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete

<7> [77.128182] i915 0000:00:02.0: [drm:intel_pps_on_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 wait for panel power on

<7> [77.128724] i915 0000:00:02.0: [drm:wait_panel_status [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063

<7> [77.160095] i915 0000:00:02.0: [drm:icp_irq_handler [i915]] hotplug event received, stat 0x00010000, dig 0x0000008a, pins 0x00000010, long 0x00000010

<7> [77.160441] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] digital hpd on [ENCODER:507:DDI A/PHY A] - long

<7> [77.160778] i915 0000:00:02.0: [drm:intel_hpd_irq_handler [i915]] Received HPD interrupt on PIN 4 - cnt: 20

<7> [77.161137] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse [i915]] ignoring long hpd on eDP [ENCODER:507:DDI A/PHY A]

<7> [77.334077] i915 0000:00:02.0: [drm:wait_panel_status [i915]] Wait complete

<7> [77.334798] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 turning VDD on

<7> [77.335355] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [i915]] [ENCODER:507:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b

<7> [77.338665] i915 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 14 c4 41 00 00 01 c0 02 00 00 00 00 0b 80

<7> [77.340253] i915 0000:00:02.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Reloading eDP link rates

<7> [77.340914] i915 0000:00:02.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 07

<7> [77.341910] i915 0000:00:02.0: [drm:intel_dp_set_signal_levels [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0

<7> [77.342997] i915 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Using DP training pattern TPS1

<7> [77.343906] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Clock recovery OK

<7> [77.344028] i915 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Using DP training pattern TPS3

<7> [77.345319] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful

<7> [77.345444] i915 0000:00:02.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:508:eDP-1][ENCODER:507:DDI A/PHY A][DPRX] Link Training passed at link rate = 540000, lane count = 4

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

<7> [77.346344] i915 0000:00:02.0: [drm:intel_edp_backlight_on [i915]]

<7> [77.346467] i915 0000:00:02.0: [drm:intel_backlight_enable [i915]] pipe C

<7> [77.346666] i915 0000:00:02.0: [drm:intel_backlight_set_pwm_level [i915]] [CONNECTOR:508:eDP-1] set backlight PWM = 13892

<7> [77.357521] i915 0000:00:02.0: [drm:intel_psr_post_plane_update [i915]] Enabling PSR1

<7> [77.358705] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:508:eDP-1]

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

<6> [78.142987] [IGT] kms_flip: finished subtest C-eDP1, FAIL

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