igt@kms_flip@flip-vs-expired-vblank-interruptible@b-edp1 on shard-lnl@IGTPW

Detail	Value
Duration	2.54 seconds
Hostname	shard-lnl-2
Igt-Version	IGT-Version: 2.4-gae9ab33a4 (x86_64) (Linux: 7.0.0-rc7-lgci-xe-xe-4886-dcbfa16156e0733d9-debug+ x86_64)
Out	Starting dynamic subtest: B-eDP1 2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 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 B-eDP1: FAIL (2.537s)
Err	Starting dynamic subtest: B-eDP1 (kms_flip:10328) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:10328) CRITICAL: Failed assertion: end - start < 500 (kms_flip:10328) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest B-eDP1 failed. ** DEBUG (kms_flip:10328) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0) (kms_flip:10328) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:10328) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:10328) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=3, pitch=11520) (kms_flip:10328) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:10328) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0) (kms_flip:10328) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:10328) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:10328) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=4, pitch=11520) (kms_flip:10328) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:10328) intel_allocator_simple-DEBUG: Using simple allocator (kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e755b0, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e755b0, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:10328) intel_allocator_simple-DEBUG: Using simple allocator (kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:10328) intel_allocator_simple-DEBUG: Using simple allocator (kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:10328) intel_allocator_simple-DEBUG: Using simple allocator (kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:10328) igt_kms-INFO: 2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa (kms_flip:10328) DEBUG: No stale events found (kms_flip:10328) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0 (kms_flip:10328) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0 (kms_flip:10328) DEBUG: name = flip last_ts = 0.000000 last_received_ts = 0.000000 last_seq = 0 current_ts = 455.690338 current_received_ts = 455.689606 current_seq = 1606 count = 0 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 79us (kms_flip:10328) DEBUG: name = flip last_ts = 455.690338 last_received_ts = 455.689606 last_seq = 1606 current_ts = 455.707001 current_received_ts = 455.706299 current_seq = 1607 count = 1 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 64us (kms_flip:10328) DEBUG: name = flip last_ts = 455.707001 last_received_ts = 455.706299 last_seq = 1607 current_ts = 455.723663 current_received_ts = 455.722992 current_seq = 1608 count = 2 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 67us (kms_flip:10328) DEBUG: name = flip last_ts = 455.723663 last_received_ts = 455.722992 last_seq = 1608 current_ts = 455.740326 current_received_ts = 455.739655 current_seq = 1609 count = 3 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 52us (kms_flip:10328) DEBUG: name = flip last_ts = 455.740326 last_received_ts = 455.739655 last_seq = 1609 current_ts = 455.756989 current_received_ts = 455.756287 current_seq = 1610 count = 4 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 455.756989 last_received_ts = 455.756287 last_seq = 1610 current_ts = 455.773651 current_received_ts = 455.772919 current_seq = 1611 count = 5 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 54us (kms_flip:10328) DEBUG: name = flip last_ts = 455.773651 last_received_ts = 455.772919 last_seq = 1611 current_ts = 455.790314 current_received_ts = 455.789612 current_seq = 1612 count = 6 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 48us (kms_flip:10328) DEBUG: name = flip last_ts = 455.790314 last_received_ts = 455.789612 last_seq = 1612 current_ts = 455.806976 current_received_ts = 455.806274 current_seq = 1613 count = 7 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 455.806976 last_received_ts = 455.806274 last_seq = 1613 current_ts = 455.823639 current_received_ts = 455.822906 current_seq = 1614 count = 8 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 455.823639 last_received_ts = 455.822906 last_seq = 1614 current_ts = 455.840302 current_received_ts = 455.839630 current_seq = 1615 count = 9 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 59us (kms_flip:10328) DEBUG: name = flip last_ts = 455.840302 last_received_ts = 455.839630 last_seq = 1615 current_ts = 455.856964 current_received_ts = 455.856262 current_seq = 1616 count = 10 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 60us (kms_flip:10328) DEBUG: name = flip last_ts = 455.856964 last_received_ts = 455.856262 last_seq = 1616 current_ts = 455.873627 current_received_ts = 455.872925 current_seq = 1617 count = 11 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 48us (kms_flip:10328) DEBUG: name = flip last_ts = 455.873627 last_received_ts = 455.872925 last_seq = 1617 current_ts = 455.890289 current_received_ts = 455.889618 current_seq = 1618 count = 12 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 49us (kms_flip:10328) DEBUG: name = flip last_ts = 455.890289 last_received_ts = 455.889618 last_seq = 1618 current_ts = 455.906952 current_received_ts = 455.906281 current_seq = 1619 count = 13 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 49us (kms_flip:10328) DEBUG: name = flip last_ts = 455.906952 last_received_ts = 455.906281 last_seq = 1619 current_ts = 455.923615 current_received_ts = 455.922913 current_seq = 1620 count = 14 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 44us (kms_flip:10328) DEBUG: name = flip last_ts = 455.923615 last_received_ts = 455.922913 last_seq = 1620 current_ts = 455.940277 current_received_ts = 455.939606 current_seq = 1621 count = 15 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 54us (kms_flip:10328) DEBUG: name = flip last_ts = 455.940277 last_received_ts = 455.939606 last_seq = 1621 current_ts = 455.956940 current_received_ts = 455.956238 current_seq = 1622 count = 16 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 53us (kms_flip:10328) DEBUG: name = flip last_ts = 455.956940 last_received_ts = 455.956238 last_seq = 1622 current_ts = 455.973602 current_received_ts = 455.972900 current_seq = 1623 count = 17 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 50us (kms_flip:10328) DEBUG: name = flip last_ts = 455.973602 last_received_ts = 455.972900 last_seq = 1623 current_ts = 455.990265 current_received_ts = 455.989624 current_seq = 1624 count = 18 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 53us (kms_flip:10328) DEBUG: name = flip last_ts = 455.990265 last_received_ts = 455.989624 last_seq = 1624 current_ts = 456.006927 current_received_ts = 456.006256 current_seq = 1625 count = 19 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 456.006927 last_received_ts = 456.006256 last_seq = 1625 current_ts = 456.023590 current_received_ts = 456.022919 current_seq = 1626 count = 20 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 42us (kms_flip:10328) DEBUG: name = flip last_ts = 456.023590 last_received_ts = 456.022919 last_seq = 1626 current_ts = 456.040253 current_received_ts = 456.039581 current_seq = 1627 count = 21 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.040253 last_received_ts = 456.039581 last_seq = 1627 current_ts = 456.056915 current_received_ts = 456.056213 current_seq = 1628 count = 22 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 48us (kms_flip:10328) DEBUG: name = flip last_ts = 456.056915 last_received_ts = 456.056213 last_seq = 1628 current_ts = 456.073578 current_received_ts = 456.072876 current_seq = 1629 count = 23 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 52us (kms_flip:10328) DEBUG: name = flip last_ts = 456.073578 last_received_ts = 456.072876 last_seq = 1629 current_ts = 456.090240 current_received_ts = 456.089569 current_seq = 1630 count = 24 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 58us (kms_flip:10328) DEBUG: name = flip last_ts = 456.090240 last_received_ts = 456.089569 last_seq = 1630 current_ts = 456.106903 current_received_ts = 456.106201 current_seq = 1631 count = 25 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.106903 last_received_ts = 456.106201 last_seq = 1631 current_ts = 456.123566 current_received_ts = 456.122833 current_seq = 1632 count = 26 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 42us (kms_flip:10328) DEBUG: name = flip last_ts = 456.123566 last_received_ts = 456.122833 last_seq = 1632 current_ts = 456.140228 current_received_ts = 456.139557 current_seq = 1633 count = 27 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 456.140228 last_received_ts = 456.139557 last_seq = 1633 current_ts = 456.156891 current_received_ts = 456.156189 current_seq = 1634 count = 28 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 56us (kms_flip:10328) DEBUG: name = flip last_ts = 456.156891 last_received_ts = 456.156189 last_seq = 1634 current_ts = 456.173553 current_received_ts = 456.172852 current_seq = 1635 count = 29 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 456.173553 last_received_ts = 456.172852 last_seq = 1635 current_ts = 456.190216 current_received_ts = 456.189514 current_seq = 1636 count = 30 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 50us (kms_flip:10328) DEBUG: name = flip last_ts = 456.190216 last_received_ts = 456.189514 last_seq = 1636 current_ts = 456.206879 current_received_ts = 456.206177 current_seq = 1637 count = 31 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 50us (kms_flip:10328) DEBUG: name = flip last_ts = 456.206879 last_received_ts = 456.206177 last_seq = 1637 current_ts = 456.223541 current_received_ts = 456.222870 current_seq = 1638 count = 32 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 52us (kms_flip:10328) DEBUG: name = flip last_ts = 456.223541 last_received_ts = 456.222870 last_seq = 1638 current_ts = 456.240204 current_received_ts = 456.239502 current_seq = 1639 count = 33 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 50us (kms_flip:10328) DEBUG: name = flip last_ts = 456.240204 last_received_ts = 456.239502 last_seq = 1639 current_ts = 456.256866 current_received_ts = 456.256165 current_seq = 1640 count = 34 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 58us (kms_flip:10328) DEBUG: name = flip last_ts = 456.256866 last_received_ts = 456.256165 last_seq = 1640 current_ts = 456.273529 current_received_ts = 456.272827 current_seq = 1641 count = 35 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 54us (kms_flip:10328) DEBUG: name = flip last_ts = 456.273529 last_received_ts = 456.272827 last_seq = 1641 current_ts = 456.290192 current_received_ts = 456.289490 current_seq = 1642 count = 36 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 53us (kms_flip:10328) DEBUG: name = flip last_ts = 456.290192 last_received_ts = 456.289490 last_seq = 1642 current_ts = 456.306854 current_received_ts = 456.306061 current_seq = 1643 count = 37 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 49us (kms_flip:10328) DEBUG: name = flip last_ts = 456.306854 last_received_ts = 456.306061 last_seq = 1643 current_ts = 456.323517 current_received_ts = 456.322815 current_seq = 1644 count = 38 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 57us (kms_flip:10328) DEBUG: name = flip last_ts = 456.323517 last_received_ts = 456.322815 last_seq = 1644 current_ts = 456.340179 current_received_ts = 456.339478 current_seq = 1645 count = 39 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 43us (kms_flip:10328) DEBUG: name = flip last_ts = 456.340179 last_received_ts = 456.339478 last_seq = 1645 current_ts = 456.356842 current_received_ts = 456.356140 current_seq = 1646 count = 40 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.356842 last_received_ts = 456.356140 last_seq = 1646 current_ts = 456.373505 current_received_ts = 456.372742 current_seq = 1647 count = 41 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.373505 last_received_ts = 456.372742 last_seq = 1647 current_ts = 456.390167 current_received_ts = 456.389465 current_seq = 1648 count = 42 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.390167 last_received_ts = 456.389465 last_seq = 1648 current_ts = 456.406830 current_received_ts = 456.406128 current_seq = 1649 count = 43 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 43us (kms_flip:10328) DEBUG: name = flip last_ts = 456.406830 last_received_ts = 456.406128 last_seq = 1649 current_ts = 456.423492 current_received_ts = 456.422791 current_seq = 1650 count = 44 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.423492 last_received_ts = 456.422791 last_seq = 1650 current_ts = 456.440155 current_received_ts = 456.439453 current_seq = 1651 count = 45 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 45us (kms_flip:10328) DEBUG: name = flip last_ts = 456.440155 last_received_ts = 456.439453 last_seq = 1651 current_ts = 456.456818 current_received_ts = 456.456116 current_seq = 1652 count = 46 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 50us (kms_flip:10328) DEBUG: name = flip last_ts = 456.456818 last_received_ts = 456.456116 last_seq = 1652 current_ts = 456.473480 current_received_ts = 456.472687 current_seq = 1653 count = 47 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 42us (kms_flip:10328) DEBUG: name = flip last_ts = 456.473480 last_received_ts = 456.472687 last_seq = 1653 current_ts = 456.490112 current_received_ts = 456.489441 current_seq = 1654 count = 48 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.490112 last_received_ts = 456.489441 last_seq = 1654 current_ts = 456.506805 current_received_ts = 456.506104 current_seq = 1655 count = 49 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 57us (kms_flip:10328) DEBUG: name = flip last_ts = 456.506805 last_received_ts = 456.506104 last_seq = 1655 current_ts = 456.523438 current_received_ts = 456.522766 current_seq = 1656 count = 50 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 53us (kms_flip:10328) DEBUG: name = flip last_ts = 456.523438 last_received_ts = 456.522766 last_seq = 1656 current_ts = 456.540131 current_received_ts = 456.539459 current_seq = 1657 count = 51 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 83us (kms_flip:10328) DEBUG: name = flip last_ts = 456.540131 last_received_ts = 456.539459 last_seq = 1657 current_ts = 456.556793 current_received_ts = 456.556061 current_seq = 1658 count = 52 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 61us (kms_flip:10328) DEBUG: name = flip last_ts = 456.556793 last_received_ts = 456.556061 last_seq = 1658 current_ts = 456.573456 current_received_ts = 456.572693 current_seq = 1659 count = 53 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 61us (kms_flip:10328) DEBUG: name = flip last_ts = 456.573456 last_received_ts = 456.572693 last_seq = 1659 current_ts = 456.590118 current_received_ts = 456.589386 current_seq = 1660 count = 54 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 57us (kms_flip:10328) DEBUG: name = flip last_ts = 456.590118 last_received_ts = 456.589386 last_seq = 1660 current_ts = 456.606750 current_received_ts = 456.606079 current_seq = 1661 count = 55 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 456.606750 last_received_ts = 456.606079 last_seq = 1661 current_ts = 456.623413 current_received_ts = 456.622742 current_seq = 1662 count = 56 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 59us (kms_flip:10328) DEBUG: name = flip last_ts = 456.623413 last_received_ts = 456.622742 last_seq = 1662 current_ts = 456.640106 current_received_ts = 456.639404 current_seq = 1663 count = 57 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.640106 last_received_ts = 456.639404 last_seq = 1663 current_ts = 456.656769 current_received_ts = 456.656067 current_seq = 1664 count = 58 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 43us (kms_flip:10328) DEBUG: name = flip last_ts = 456.656769 last_received_ts = 456.656067 last_seq = 1664 current_ts = 456.673431 current_received_ts = 456.672668 current_seq = 1665 count = 59 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 51us (kms_flip:10328) DEBUG: name = flip last_ts = 456.673431 last_received_ts = 456.672668 last_seq = 1665 current_ts = 456.690094 current_received_ts = 456.689392 current_seq = 1666 count = 60 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 54us (kms_flip:10328) DEBUG: name = flip last_ts = 456.690094 last_received_ts = 456.689392 last_seq = 1666 current_ts = 456.706757 current_received_ts = 456.706055 current_seq = 1667 count = 61 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 54us (kms_flip:10328) DEBUG: name = flip last_ts = 456.706757 last_received_ts = 456.706055 last_seq = 1667 current_ts = 456.723419 current_received_ts = 456.722717 current_seq = 1668 count = 62 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 56us (kms_flip:10328) DEBUG: name = flip last_ts = 456.723419 last_received_ts = 456.722717 last_seq = 1668 current_ts = 456.740082 current_received_ts = 456.739380 current_seq = 1669 count = 63 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 456.740082 last_received_ts = 456.739380 last_seq = 1669 current_ts = 456.756714 current_received_ts = 456.756073 current_seq = 1670 count = 64 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 138us (kms_flip:10328) DEBUG: name = flip last_ts = 456.756714 last_received_ts = 456.756073 last_seq = 1670 current_ts = 456.773376 current_received_ts = 456.772736 current_seq = 1671 count = 65 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 75us (kms_flip:10328) DEBUG: name = flip last_ts = 456.773376 last_received_ts = 456.772736 last_seq = 1671 current_ts = 456.790039 current_received_ts = 456.789398 current_seq = 1672 count = 66 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 63us (kms_flip:10328) DEBUG: name = flip last_ts = 456.790039 last_received_ts = 456.789398 last_seq = 1672 current_ts = 456.806732 current_received_ts = 456.806061 current_seq = 1673 count = 67 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 56us (kms_flip:10328) DEBUG: name = flip last_ts = 456.806732 last_received_ts = 456.806061 last_seq = 1673 current_ts = 456.823364 current_received_ts = 456.822723 current_seq = 1674 count = 68 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 57us (kms_flip:10328) DEBUG: name = flip last_ts = 456.823364 last_received_ts = 456.822723 last_seq = 1674 current_ts = 456.840057 current_received_ts = 456.839355 current_seq = 1675 count = 69 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 50us (kms_flip:10328) DEBUG: name = flip last_ts = 456.840057 last_received_ts = 456.839355 last_seq = 1675 current_ts = 456.856720 current_received_ts = 456.856049 current_seq = 1676 count = 70 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 93us (kms_flip:10328) DEBUG: name = flip last_ts = 456.856720 last_received_ts = 456.856049 last_seq = 1676 current_ts = 456.873352 current_received_ts = 456.872681 current_seq = 1677 count = 71 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 64us (kms_flip:10328) DEBUG: name = flip last_ts = 456.873352 last_received_ts = 456.872681 last_seq = 1677 current_ts = 456.890015 current_received_ts = 456.889343 current_seq = 1678 count = 72 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 65us (kms_flip:10328) DEBUG: name = flip last_ts = 456.890015 last_received_ts = 456.889343 last_seq = 1678 current_ts = 456.906677 current_received_ts = 456.906036 current_seq = 1679 count = 73 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 62us (kms_flip:10328) DEBUG: name = flip last_ts = 456.906677 last_received_ts = 456.906036 last_seq = 1679 current_ts = 456.923340 current_received_ts = 456.922668 current_seq = 1680 count = 74 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 44us (kms_flip:10328) DEBUG: name = flip last_ts = 456.923340 last_received_ts = 456.922668 last_seq = 1680 current_ts = 456.940002 current_received_ts = 456.939331 current_seq = 1681 count = 75 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 55us (kms_flip:10328) DEBUG: name = flip last_ts = 456.940002 last_received_ts = 456.939331 last_seq = 1681 current_ts = 456.956665 current_received_ts = 456.956024 current_seq = 1682 count = 76 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 42us (kms_flip:10328) DEBUG: name = flip last_ts = 456.956665 last_received_ts = 456.956024 last_seq = 1682 current_ts = 456.973328 current_received_ts = 456.972656 current_seq = 1683 count = 77 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 50us (kms_flip:10328) DEBUG: name = flip last_ts = 456.973328 last_received_ts = 456.972656 last_seq = 1683 current_ts = 456.989990 current_received_ts = 456.989288 current_seq = 1684 count = 78 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 54us (kms_flip:10328) DEBUG: name = flip last_ts = 456.989990 last_received_ts = 456.989288 last_seq = 1684 current_ts = 457.006683 current_received_ts = 457.005981 current_seq = 1685 count = 79 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 72us (kms_flip:10328) DEBUG: name = flip last_ts = 457.006683 last_received_ts = 457.005981 last_seq = 1685 current_ts = 457.023346 current_received_ts = 457.022644 current_seq = 1686 count = 80 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 49us (kms_flip:10328) DEBUG: name = flip last_ts = 457.023346 last_received_ts = 457.022644 last_seq = 1686 current_ts = 457.040009 current_received_ts = 457.039307 current_seq = 1687 count = 81 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 42us (kms_flip:10328) DEBUG: name = flip last_ts = 457.040009 last_received_ts = 457.039307 last_seq = 1687 current_ts = 457.056641 current_received_ts = 457.055969 current_seq = 1688 count = 82 seq_step = 1 (kms_flip:10328) DEBUG: Vblank took 701us (kms_flip:10328) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:10328) CRITICAL: Failed assertion: end - start < 500 (kms_flip:10328) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:10328) igt_core-INFO: Stack trace: (kms_flip:10328) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:10328) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:10328) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:10328) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() (kms_flip:10328) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:10328) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:10328) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:10328) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-eDP1: FAIL (2.537s)
Dmesg	<6> [468.337700] [IGT] kms_flip: starting dynamic subtest B-eDP1 <7> [468.358247] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:433] <7> [468.358960] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:434] <7> [468.416337] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [468.416413] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [468.416532] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [468.416638] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [468.416757] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [468.416878] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0) <7> [468.416986] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [468.417077] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [468.417168] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [468.417256] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [468.417342] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [468.417427] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [468.417511] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [468.417593] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [468.417696] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [468.417803] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [468.417906] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [468.417998] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [468.418077] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [468.418154] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [468.418231] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [468.418307] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [468.418384] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [468.418460] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [468.418536] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [468.418611] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [468.418707] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [468.418805] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [468.418902] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [468.418989] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [468.419066] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [468.419139] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [468.419212] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [468.419285] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [468.419358] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [468.419433] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [468.419506] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [468.419578] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [468.419655] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0) <7> [468.419748] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [468.419845] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0 <7> [468.419975] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [468.420042] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [468.420128] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [468.420189] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [468.420246] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm <7> [468.420303] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [468.420360] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [468.420414] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [468.420487] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0 <7> [468.420573] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [468.420668] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [468.420777] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [468.420884] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [468.420984] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [468.421067] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [468.421170] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [468.421254] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [468.421334] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [468.421414] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [468.421525] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset] <7> [468.421609] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no <7> [468.421714] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [468.421820] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [468.421925] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [468.422019] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [468.422100] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [468.422237] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [468.422337] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [468.422481] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [468.422662] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on <7> [468.422782] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f <7> [468.423379] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [468.423488] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [468.629957] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0 <7> [468.630509] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [468.640077] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off <7> [468.640595] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time <7> [468.640587] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [468.641181] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [468.641263] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short <7> [468.692540] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [468.692895] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [468.693137] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A] <7> [468.693187] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [468.693411] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short <7> [468.694013] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [468.694915] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [468.695587] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [468.696343] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A] <7> [468.696857] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1] <7> [468.697261] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A] <7> [468.697618] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B] <7> [468.698072] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C] <7> [468.698383] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2] <7> [468.698697] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A] <7> [468.698997] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B] <7> [468.699360] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C] <7> [468.699708] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3] <7> [468.700037] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A] <7> [468.700395] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B] <7> [468.700700] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C] <7> [468.700995] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1] <7> [468.701484] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [468.701854] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [468.702191] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [468.702741] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [468.703155] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000) <7> [468.703713] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [468.704101] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [468.704631] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [468.705095] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [468.706521] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B] <7> [468.706911] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C] <7> [468.707202] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B] <7> [468.707272] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1] <7> [468.707442] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [468.707826] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:270:pipe B] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000 <7> [468.708142] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000 <7> [468.708467] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [468.708790] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:270:pipe B] <7> [468.709074] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.enable (expected no, found yes) <7> [468.709347] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.active (expected no, found yes) <7> [468.709603] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1) <7> [468.709935] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in lane_count (expected 0, found 4) <7> [468.710171] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288) <7> [468.710398] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [468.710616] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [468.710841] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [468.711076] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [468.711285] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880) <7> [468.711471] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040) <7> [468.711675] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928) <7> [468.711850] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960) <7> [468.712017] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [468.712183] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800) <7> [468.712347] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803) <7> [468.712502] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809) <7> [468.712652] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [468.712836] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906) <7> [468.712978] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [468.713113] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [468.713250] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880) <7> [468.713382] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040) <7> [468.713528] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928) <7> [468.713667] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960) <7> [468.713788] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [468.713909] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800) <7> [468.714034] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803) <7> [468.714157] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809) <7> [468.714281] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [468.714399] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906) <7> [468.714513] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [468.714625] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [468.714752] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [468.714873] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [468.714992] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [468.715103] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [468.715203] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in port_clock (expected 0, found 432000) <7> [468.715302] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] fastset requirement not met, forcing full modeset <7> [468.715430] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [468.715512] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:270:pipe B] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x2 <7> [468.715639] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:154:plane 1B] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [468.715740] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:264:cursor B] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [468.715810] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm <7> [468.715875] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 <7> [468.715940] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 <7> [468.716004] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 <7> [468.716084] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:270:pipe B] data rate 1390840 num active planes 1 <7> [468.716185] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [468.716281] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [468.716373] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [468.716462] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [468.716547] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [468.716632] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:270:pipe B] min cdclk: 0 kHz -> 173855 kHz <7> [468.716756] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [468.716846] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [468.716933] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [468.717018] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [468.717113] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:270:pipe B] allocated DPLL 0 <7> [468.717196] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:270:pipe B] reserving DPLL 0 <7> [468.717273] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:270:pipe B] enable: yes [modeset] <7> [468.717358] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [468.717441] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: B, pipe bpp: 30, dithering: 0 <7> [468.717523] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [468.717605] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [468.717691] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [468.717778] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [468.717864] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64 <7> [468.717950] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0 <7> [468.718034] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [468.718111] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [468.718188] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [468.718265] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0 <7> [468.718339] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [468.718416] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [468.718492] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [468.718568] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [468.718642] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [468.718732] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [468.718814] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [468.718895] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [468.718976] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [468.719054] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97 <7> [468.719127] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906 <7> [468.719201] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [468.719276] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [468.719351] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [468.719424] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [468.719498] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [468.719571] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [468.719646] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0 <7> [468.719798] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [468.719883] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [468.719969] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0 <7> [468.720052] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [468.720129] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [468.720204] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [468.720279] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no <7> [468.720354] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no, <7> [468.720428] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1. <7> [468.720503] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [468.720577] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [468.720651] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1 <7> [468.720746] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [468.720827] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [468.720907] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [468.720986] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23 <7> [468.721065] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [468.721137] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [468.721209] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [468.721281] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [468.721357] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [468.721439] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [468.721522] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [468.721600] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [468.721677] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [468.721755] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [468.721835] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [468.721918] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [468.722000] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:154:plane 1B] fb: [FB:433] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [468.722076] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [468.722150] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [468.722224] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:184:plane 2B] fb: [NOFB], visible: no <7> [468.722299] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:214:plane 3B] fb: [NOFB], visible: no <7> [468.722373] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:244:plane 4B] fb: [NOFB], visible: no <7> [468.722452] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:254:plane 5B] fb: [NOFB], visible: no <7> [468.722526] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:264:cursor B] fb: [NOFB], visible: no <7> [468.722849] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_2 <7> [468.722977] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_B <7> [468.723112] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x2 (CLKGATE_DIS_DSSDSC=0xa2000000) <7> [468.723205] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [468.723293] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [468.723380] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [468.723462] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A] <7> [468.723532] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1] <7> [468.723601] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A] <7> [468.723677] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B] <7> [468.723751] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C] <7> [468.723823] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2] <7> [468.723893] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A] <7> [468.723962] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B] <7> [468.724027] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C] <7> [468.724089] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3] <7> [468.724150] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A] <7> [468.724210] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B] <7> [468.724269] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C] <7> [468.724349] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [468.724504] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [468.724565] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [468.724675] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [468.725694] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x2, on? 0) for [CRTC:270:pipe B] <7> [468.725790] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [468.727765] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on <7> [468.727860] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (466 ms remaining) <7> [468.730684] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [468.730804] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long <7> [468.730922] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [468.731074] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [469.198054] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [469.208622] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [469.209303] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on <7> [469.209877] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [469.245457] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [469.246032] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long <7> [469.246564] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [469.247124] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [469.423555] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [469.424070] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on <7> [469.424456] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [469.426660] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80 <7> [469.428281] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [469.429207] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05 <7> [469.430514] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [469.432157] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [469.433505] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK <7> [469.434122] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [469.435890] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [469.436492] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4 <7> [469.437511] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe B <7> [469.438179] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [469.438645] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe B <7> [469.439221] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 13892 <7> [469.455137] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [469.457012] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1] <7> [469.457498] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:270:pipe B] <7> [470.871915] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [470.872325] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [470.872595] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [470.875564] [IGT] kms_flip: finished subtest B-eDP1, FAIL

Detail

Value

Duration

2.54 seconds

Hostname

shard-lnl-2

Igt-Version

IGT-Version: 2.4-gae9ab33a4 (x86_64) (Linux: 7.0.0-rc7-lgci-xe-xe-4886-dcbfa16156e0733d9-debug+ x86_64)

Out

Starting dynamic subtest: B-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 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 B-eDP1: FAIL (2.537s)

Err

Starting dynamic subtest: B-eDP1
(kms_flip:10328) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:10328) CRITICAL: Failed assertion: end - start < 500
(kms_flip:10328) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-eDP1 failed.
**** DEBUG ****
(kms_flip:10328) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0)
(kms_flip:10328) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:10328) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:10328) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=3, pitch=11520)
(kms_flip:10328) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:10328) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0)
(kms_flip:10328) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:10328) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:10328) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=4, pitch=11520)
(kms_flip:10328) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:10328) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e755b0, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e755b0, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:10328) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:10328) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:10328) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:10328) intel_allocator_simple-DEBUG: <ial: 0x5ea123e61b00, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:10328) igt_kms-INFO:   2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
(kms_flip:10328) DEBUG: No stale events found
(kms_flip:10328) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:10328) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:10328) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 455.690338
current_received_ts = 455.689606
current_seq = 1606
count = 0
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 79us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.690338
last_received_ts = 455.689606
last_seq = 1606
current_ts = 455.707001
current_received_ts = 455.706299
current_seq = 1607
count = 1
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 64us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.707001
last_received_ts = 455.706299
last_seq = 1607
current_ts = 455.723663
current_received_ts = 455.722992
current_seq = 1608
count = 2
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 67us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.723663
last_received_ts = 455.722992
last_seq = 1608
current_ts = 455.740326
current_received_ts = 455.739655
current_seq = 1609
count = 3
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 52us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.740326
last_received_ts = 455.739655
last_seq = 1609
current_ts = 455.756989
current_received_ts = 455.756287
current_seq = 1610
count = 4
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.756989
last_received_ts = 455.756287
last_seq = 1610
current_ts = 455.773651
current_received_ts = 455.772919
current_seq = 1611
count = 5
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 54us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.773651
last_received_ts = 455.772919
last_seq = 1611
current_ts = 455.790314
current_received_ts = 455.789612
current_seq = 1612
count = 6
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 48us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.790314
last_received_ts = 455.789612
last_seq = 1612
current_ts = 455.806976
current_received_ts = 455.806274
current_seq = 1613
count = 7
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.806976
last_received_ts = 455.806274
last_seq = 1613
current_ts = 455.823639
current_received_ts = 455.822906
current_seq = 1614
count = 8
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.823639
last_received_ts = 455.822906
last_seq = 1614
current_ts = 455.840302
current_received_ts = 455.839630
current_seq = 1615
count = 9
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 59us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.840302
last_received_ts = 455.839630
last_seq = 1615
current_ts = 455.856964
current_received_ts = 455.856262
current_seq = 1616
count = 10
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 60us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.856964
last_received_ts = 455.856262
last_seq = 1616
current_ts = 455.873627
current_received_ts = 455.872925
current_seq = 1617
count = 11
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 48us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.873627
last_received_ts = 455.872925
last_seq = 1617
current_ts = 455.890289
current_received_ts = 455.889618
current_seq = 1618
count = 12
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 49us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.890289
last_received_ts = 455.889618
last_seq = 1618
current_ts = 455.906952
current_received_ts = 455.906281
current_seq = 1619
count = 13
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 49us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.906952
last_received_ts = 455.906281
last_seq = 1619
current_ts = 455.923615
current_received_ts = 455.922913
current_seq = 1620
count = 14
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 44us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.923615
last_received_ts = 455.922913
last_seq = 1620
current_ts = 455.940277
current_received_ts = 455.939606
current_seq = 1621
count = 15
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 54us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.940277
last_received_ts = 455.939606
last_seq = 1621
current_ts = 455.956940
current_received_ts = 455.956238
current_seq = 1622
count = 16
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 53us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.956940
last_received_ts = 455.956238
last_seq = 1622
current_ts = 455.973602
current_received_ts = 455.972900
current_seq = 1623
count = 17
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 50us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.973602
last_received_ts = 455.972900
last_seq = 1623
current_ts = 455.990265
current_received_ts = 455.989624
current_seq = 1624
count = 18
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 53us
(kms_flip:10328) DEBUG: name = flip
last_ts = 455.990265
last_received_ts = 455.989624
last_seq = 1624
current_ts = 456.006927
current_received_ts = 456.006256
current_seq = 1625
count = 19
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.006927
last_received_ts = 456.006256
last_seq = 1625
current_ts = 456.023590
current_received_ts = 456.022919
current_seq = 1626
count = 20
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 42us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.023590
last_received_ts = 456.022919
last_seq = 1626
current_ts = 456.040253
current_received_ts = 456.039581
current_seq = 1627
count = 21
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.040253
last_received_ts = 456.039581
last_seq = 1627
current_ts = 456.056915
current_received_ts = 456.056213
current_seq = 1628
count = 22
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 48us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.056915
last_received_ts = 456.056213
last_seq = 1628
current_ts = 456.073578
current_received_ts = 456.072876
current_seq = 1629
count = 23
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 52us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.073578
last_received_ts = 456.072876
last_seq = 1629
current_ts = 456.090240
current_received_ts = 456.089569
current_seq = 1630
count = 24
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 58us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.090240
last_received_ts = 456.089569
last_seq = 1630
current_ts = 456.106903
current_received_ts = 456.106201
current_seq = 1631
count = 25
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.106903
last_received_ts = 456.106201
last_seq = 1631
current_ts = 456.123566
current_received_ts = 456.122833
current_seq = 1632
count = 26
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 42us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.123566
last_received_ts = 456.122833
last_seq = 1632
current_ts = 456.140228
current_received_ts = 456.139557
current_seq = 1633
count = 27
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.140228
last_received_ts = 456.139557
last_seq = 1633
current_ts = 456.156891
current_received_ts = 456.156189
current_seq = 1634
count = 28
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 56us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.156891
last_received_ts = 456.156189
last_seq = 1634
current_ts = 456.173553
current_received_ts = 456.172852
current_seq = 1635
count = 29
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.173553
last_received_ts = 456.172852
last_seq = 1635
current_ts = 456.190216
current_received_ts = 456.189514
current_seq = 1636
count = 30
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 50us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.190216
last_received_ts = 456.189514
last_seq = 1636
current_ts = 456.206879
current_received_ts = 456.206177
current_seq = 1637
count = 31
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 50us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.206879
last_received_ts = 456.206177
last_seq = 1637
current_ts = 456.223541
current_received_ts = 456.222870
current_seq = 1638
count = 32
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 52us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.223541
last_received_ts = 456.222870
last_seq = 1638
current_ts = 456.240204
current_received_ts = 456.239502
current_seq = 1639
count = 33
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 50us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.240204
last_received_ts = 456.239502
last_seq = 1639
current_ts = 456.256866
current_received_ts = 456.256165
current_seq = 1640
count = 34
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 58us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.256866
last_received_ts = 456.256165
last_seq = 1640
current_ts = 456.273529
current_received_ts = 456.272827
current_seq = 1641
count = 35
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 54us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.273529
last_received_ts = 456.272827
last_seq = 1641
current_ts = 456.290192
current_received_ts = 456.289490
current_seq = 1642
count = 36
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 53us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.290192
last_received_ts = 456.289490
last_seq = 1642
current_ts = 456.306854
current_received_ts = 456.306061
current_seq = 1643
count = 37
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 49us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.306854
last_received_ts = 456.306061
last_seq = 1643
current_ts = 456.323517
current_received_ts = 456.322815
current_seq = 1644
count = 38
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 57us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.323517
last_received_ts = 456.322815
last_seq = 1644
current_ts = 456.340179
current_received_ts = 456.339478
current_seq = 1645
count = 39
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 43us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.340179
last_received_ts = 456.339478
last_seq = 1645
current_ts = 456.356842
current_received_ts = 456.356140
current_seq = 1646
count = 40
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.356842
last_received_ts = 456.356140
last_seq = 1646
current_ts = 456.373505
current_received_ts = 456.372742
current_seq = 1647
count = 41
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.373505
last_received_ts = 456.372742
last_seq = 1647
current_ts = 456.390167
current_received_ts = 456.389465
current_seq = 1648
count = 42
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.390167
last_received_ts = 456.389465
last_seq = 1648
current_ts = 456.406830
current_received_ts = 456.406128
current_seq = 1649
count = 43
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 43us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.406830
last_received_ts = 456.406128
last_seq = 1649
current_ts = 456.423492
current_received_ts = 456.422791
current_seq = 1650
count = 44
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.423492
last_received_ts = 456.422791
last_seq = 1650
current_ts = 456.440155
current_received_ts = 456.439453
current_seq = 1651
count = 45
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 45us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.440155
last_received_ts = 456.439453
last_seq = 1651
current_ts = 456.456818
current_received_ts = 456.456116
current_seq = 1652
count = 46
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 50us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.456818
last_received_ts = 456.456116
last_seq = 1652
current_ts = 456.473480
current_received_ts = 456.472687
current_seq = 1653
count = 47
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 42us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.473480
last_received_ts = 456.472687
last_seq = 1653
current_ts = 456.490112
current_received_ts = 456.489441
current_seq = 1654
count = 48
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.490112
last_received_ts = 456.489441
last_seq = 1654
current_ts = 456.506805
current_received_ts = 456.506104
current_seq = 1655
count = 49
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 57us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.506805
last_received_ts = 456.506104
last_seq = 1655
current_ts = 456.523438
current_received_ts = 456.522766
current_seq = 1656
count = 50
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 53us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.523438
last_received_ts = 456.522766
last_seq = 1656
current_ts = 456.540131
current_received_ts = 456.539459
current_seq = 1657
count = 51
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 83us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.540131
last_received_ts = 456.539459
last_seq = 1657
current_ts = 456.556793
current_received_ts = 456.556061
current_seq = 1658
count = 52
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 61us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.556793
last_received_ts = 456.556061
last_seq = 1658
current_ts = 456.573456
current_received_ts = 456.572693
current_seq = 1659
count = 53
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 61us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.573456
last_received_ts = 456.572693
last_seq = 1659
current_ts = 456.590118
current_received_ts = 456.589386
current_seq = 1660
count = 54
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 57us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.590118
last_received_ts = 456.589386
last_seq = 1660
current_ts = 456.606750
current_received_ts = 456.606079
current_seq = 1661
count = 55
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.606750
last_received_ts = 456.606079
last_seq = 1661
current_ts = 456.623413
current_received_ts = 456.622742
current_seq = 1662
count = 56
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 59us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.623413
last_received_ts = 456.622742
last_seq = 1662
current_ts = 456.640106
current_received_ts = 456.639404
current_seq = 1663
count = 57
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.640106
last_received_ts = 456.639404
last_seq = 1663
current_ts = 456.656769
current_received_ts = 456.656067
current_seq = 1664
count = 58
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 43us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.656769
last_received_ts = 456.656067
last_seq = 1664
current_ts = 456.673431
current_received_ts = 456.672668
current_seq = 1665
count = 59
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 51us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.673431
last_received_ts = 456.672668
last_seq = 1665
current_ts = 456.690094
current_received_ts = 456.689392
current_seq = 1666
count = 60
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 54us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.690094
last_received_ts = 456.689392
last_seq = 1666
current_ts = 456.706757
current_received_ts = 456.706055
current_seq = 1667
count = 61
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 54us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.706757
last_received_ts = 456.706055
last_seq = 1667
current_ts = 456.723419
current_received_ts = 456.722717
current_seq = 1668
count = 62
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 56us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.723419
last_received_ts = 456.722717
last_seq = 1668
current_ts = 456.740082
current_received_ts = 456.739380
current_seq = 1669
count = 63
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.740082
last_received_ts = 456.739380
last_seq = 1669
current_ts = 456.756714
current_received_ts = 456.756073
current_seq = 1670
count = 64
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 138us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.756714
last_received_ts = 456.756073
last_seq = 1670
current_ts = 456.773376
current_received_ts = 456.772736
current_seq = 1671
count = 65
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 75us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.773376
last_received_ts = 456.772736
last_seq = 1671
current_ts = 456.790039
current_received_ts = 456.789398
current_seq = 1672
count = 66
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 63us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.790039
last_received_ts = 456.789398
last_seq = 1672
current_ts = 456.806732
current_received_ts = 456.806061
current_seq = 1673
count = 67
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 56us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.806732
last_received_ts = 456.806061
last_seq = 1673
current_ts = 456.823364
current_received_ts = 456.822723
current_seq = 1674
count = 68
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 57us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.823364
last_received_ts = 456.822723
last_seq = 1674
current_ts = 456.840057
current_received_ts = 456.839355
current_seq = 1675
count = 69
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 50us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.840057
last_received_ts = 456.839355
last_seq = 1675
current_ts = 456.856720
current_received_ts = 456.856049
current_seq = 1676
count = 70
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 93us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.856720
last_received_ts = 456.856049
last_seq = 1676
current_ts = 456.873352
current_received_ts = 456.872681
current_seq = 1677
count = 71
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 64us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.873352
last_received_ts = 456.872681
last_seq = 1677
current_ts = 456.890015
current_received_ts = 456.889343
current_seq = 1678
count = 72
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 65us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.890015
last_received_ts = 456.889343
last_seq = 1678
current_ts = 456.906677
current_received_ts = 456.906036
current_seq = 1679
count = 73
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 62us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.906677
last_received_ts = 456.906036
last_seq = 1679
current_ts = 456.923340
current_received_ts = 456.922668
current_seq = 1680
count = 74
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 44us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.923340
last_received_ts = 456.922668
last_seq = 1680
current_ts = 456.940002
current_received_ts = 456.939331
current_seq = 1681
count = 75
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 55us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.940002
last_received_ts = 456.939331
last_seq = 1681
current_ts = 456.956665
current_received_ts = 456.956024
current_seq = 1682
count = 76
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 42us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.956665
last_received_ts = 456.956024
last_seq = 1682
current_ts = 456.973328
current_received_ts = 456.972656
current_seq = 1683
count = 77
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 50us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.973328
last_received_ts = 456.972656
last_seq = 1683
current_ts = 456.989990
current_received_ts = 456.989288
current_seq = 1684
count = 78
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 54us
(kms_flip:10328) DEBUG: name = flip
last_ts = 456.989990
last_received_ts = 456.989288
last_seq = 1684
current_ts = 457.006683
current_received_ts = 457.005981
current_seq = 1685
count = 79
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 72us
(kms_flip:10328) DEBUG: name = flip
last_ts = 457.006683
last_received_ts = 457.005981
last_seq = 1685
current_ts = 457.023346
current_received_ts = 457.022644
current_seq = 1686
count = 80
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 49us
(kms_flip:10328) DEBUG: name = flip
last_ts = 457.023346
last_received_ts = 457.022644
last_seq = 1686
current_ts = 457.040009
current_received_ts = 457.039307
current_seq = 1687
count = 81
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 42us
(kms_flip:10328) DEBUG: name = flip
last_ts = 457.040009
last_received_ts = 457.039307
last_seq = 1687
current_ts = 457.056641
current_received_ts = 457.055969
current_seq = 1688
count = 82
seq_step = 1
(kms_flip:10328) DEBUG: Vblank took 701us
(kms_flip:10328) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:10328) CRITICAL: Failed assertion: end - start < 500
(kms_flip:10328) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:10328) igt_core-INFO: Stack trace:
(kms_flip:10328) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:10328) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:10328) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:10328) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:10328) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:10328) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:10328) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:10328) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-eDP1: FAIL (2.537s)

Dmesg

<6> [468.337700] [IGT] kms_flip: starting dynamic subtest B-eDP1

<7> [468.358247] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:433]

<7> [468.358960] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:434]

<7> [468.416337] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

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

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

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

<7> [468.416878] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [468.419845] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0

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

<7> [468.420042] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0

<7> [468.420128] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0

<7> [468.420189] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0

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

<7> [468.420303] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [468.420360] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [468.420414] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [468.420487] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0

<7> [468.420573] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400

<7> [468.420668] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400

<7> [468.420777] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400

<7> [468.420884] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400

<7> [468.420984] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0

<7> [468.421067] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz

<7> [468.421170] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz

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

<7> [468.421334] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz

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

<7> [468.421525] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]

<7> [468.421609] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no

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

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

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

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

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

<7> [468.422237] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off

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

<7> [468.422481] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2

<7> [468.422662] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on

<7> [468.422782] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006f

<7> [468.423379] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM

<7> [468.423488] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]

<7> [468.629957] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0

<7> [468.630509] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A

<7> [468.640077] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off

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

<7> [468.640587] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000

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

<7> [468.641263] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short

<7> [468.692540] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [468.692895] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000

<7> [468.693137] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]

<7> [468.693187] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]

<7> [468.693411] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short

<7> [468.694013] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]

<7> [468.694915] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0

<7> [468.695587] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A

<7> [468.696343] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]

<7> [468.696857] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]

<7> [468.697261] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]

<7> [468.697618] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]

<7> [468.698072] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]

<7> [468.698383] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]

<7> [468.698697] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]

<7> [468.698997] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]

<7> [468.699360] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]

<7> [468.699708] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]

<7> [468.700037] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]

<7> [468.700395] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]

<7> [468.700700] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]

<7> [468.700995] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]

<7> [468.701484] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

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

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

<7> [468.702741] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A

<7> [468.703155] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)

<7> [468.703713] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

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

<7> [468.704631] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [468.705095] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384

<7> [468.706521] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]

<7> [468.706911] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]

<7> [468.707202] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]

<7> [468.707272] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]

<7> [468.707442] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)

<7> [468.707826] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:270:pipe B] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000

<7> [468.708142] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000

<7> [468.708467] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] hw max bpp: 30, pipe bpp: 30, dithering: 0

<7> [468.708790] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:270:pipe B]

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

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

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

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

<7> [468.710171] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)

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

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

<7> [468.710841] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)

<7> [468.711076] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)

<7> [468.711285] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)

<7> [468.711471] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)

<7> [468.711675] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)

<7> [468.711850] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)

<7> [468.712017] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)

<7> [468.712183] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)

<7> [468.712347] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)

<7> [468.712502] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)

<7> [468.712652] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)

<7> [468.712836] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)

<7> [468.712978] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)

<7> [468.713113] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)

<7> [468.713250] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)

<7> [468.713382] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)

<7> [468.713528] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)

<7> [468.713667] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)

<7> [468.713788] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)

<7> [468.713909] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)

<7> [468.714034] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)

<7> [468.714157] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)

<7> [468.714281] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)

<7> [468.714399] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)

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

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

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

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

<7> [468.714992] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)

<7> [468.715103] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)

<7> [468.715203] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in port_clock (expected 0, found 432000)

<7> [468.715302] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] fastset requirement not met, forcing full modeset

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

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

<7> [468.715639] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:154:plane 1B] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051

<7> [468.715740] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:264:cursor B] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45

<7> [468.715810] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm

<7> [468.715875] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0

<7> [468.715940] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197

<7> [468.716004] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198

<7> [468.716084] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:270:pipe B] data rate 1390840 num active planes 1

<7> [468.716185] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400

<7> [468.716281] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400

<7> [468.716373] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400

<7> [468.716462] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400

<7> [468.716547] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461

<7> [468.716632] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:270:pipe B] min cdclk: 0 kHz -> 173855 kHz

<7> [468.716756] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz

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

<7> [468.716933] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz

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

<7> [468.717113] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:270:pipe B] allocated DPLL 0

<7> [468.717196] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:270:pipe B] reserving DPLL 0

<7> [468.717273] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:270:pipe B] enable: yes [modeset]

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

<7> [468.717441] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: B, pipe bpp: 30, dithering: 0

<7> [468.717523] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>

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

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

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

<7> [468.717864] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64

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

<7> [468.718034] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled

<7> [468.718111] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled

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

<7> [468.718265] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0

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

<7> [468.718416] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14

<7> [468.718492] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB

<7> [468.718568] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB

<7> [468.718642] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0

<7> [468.718732] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range

<7> [468.718814] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined

<7> [468.718895] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1

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

<7> [468.719054] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97

<7> [468.719127] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906

<7> [468.719201] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0

<7> [468.719276] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [468.719351] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [468.719424] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa

<7> [468.719498] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa

<7> [468.719571] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa

<7> [468.719646] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0

<7> [468.719798] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0

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

<7> [468.719969] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0

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

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

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

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

<7> [468.720354] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,

<7> [468.720428] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.

<7> [468.720503] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:

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

<7> [468.720651] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1

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

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

<7> [468.720907] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1

<7> [468.720986] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23

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

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

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

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

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

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

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

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

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

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

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

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

<7> [468.722000] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:154:plane 1B] fb: [FB:433] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes

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

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

<7> [468.722224] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:184:plane 2B] fb: [NOFB], visible: no

<7> [468.722299] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:214:plane 3B] fb: [NOFB], visible: no

<7> [468.722373] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:244:plane 4B] fb: [NOFB], visible: no

<7> [468.722452] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:254:plane 5B] fb: [NOFB], visible: no

<7> [468.722526] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:264:cursor B] fb: [NOFB], visible: no

<7> [468.722849] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_2

<7> [468.722977] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_B

<7> [468.723112] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x2 (CLKGATE_DIS_DSSDSC=0xa2000000)

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

<7> [468.723293] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [468.723380] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480

<7> [468.723462] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]

<7> [468.723532] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]

<7> [468.723601] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]

<7> [468.723677] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]

<7> [468.723751] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]

<7> [468.723823] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]

<7> [468.723893] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]

<7> [468.723962] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]

<7> [468.724027] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]

<7> [468.724089] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]

<7> [468.724150] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]

<7> [468.724210] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]

<7> [468.724269] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]

<7> [468.724349] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf

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

<7> [468.724565] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)

<7> [468.724675] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A

<7> [468.725694] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x2, on? 0) for [CRTC:270:pipe B]

<7> [468.725790] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0

<7> [468.727765] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on

<7> [468.727860] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (466 ms remaining)

<7> [468.730684] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010

<7> [468.730804] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long

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

<7> [468.731074] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]

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

<7> [469.208622] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [469.209303] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on

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

<7> [469.245457] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010

<7> [469.246032] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long

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

<7> [469.247124] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]

<7> [469.423555] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [469.424070] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on

<7> [469.424456] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b

<7> [469.426660] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80

<7> [469.428281] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates

<7> [469.429207] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05

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

<7> [469.432157] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1

<7> [469.433505] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK

<7> [469.434122] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4

<7> [469.435890] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful

<7> [469.436492] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4

<7> [469.437511] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe B

<7> [469.438179] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]

<7> [469.438645] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe B

<7> [469.439221] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 13892

<7> [469.455137] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2

<7> [469.457012] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]

<7> [469.457498] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:270:pipe B]

<7> [470.871915] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off

<7> [470.872325] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6

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

<6> [470.875564] [IGT] kms_flip: finished subtest B-eDP1, FAIL

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