igt@kms_flip@flip-vs-expired-vblank@a-edp1 on shard-lnl@xe-4557-0558a31efefc20e307523a43c37a29f4eab171dc Test details

Detail	Value
Duration	3.91 seconds
Hostname	shard-lnl-5
Igt-Version	IGT-Version: 2.3-g07ca77c0e (x86_64) (Linux: 6.19.0-lgci-xe-xe-4557-0558a31efefc20e30-debug+ x86_64)
Out	Using IGT_SRANDOM=1771100265 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-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:921 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1887 run_test() #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043() #4 ../tests/kms_flip.c:2043 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (3.913s)
Err	Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 (kms_flip:3780) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:3780) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:3780) DEBUG: name = flip last_ts = 195.241501 last_received_ts = 195.240814 last_seq = 1729 current_ts = 195.258163 current_received_ts = 195.257477 current_seq = 1730 count = 32 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 109us (kms_flip:3780) DEBUG: name = flip last_ts = 195.258163 last_received_ts = 195.257477 last_seq = 1730 current_ts = 195.274826 current_received_ts = 195.274185 current_seq = 1731 count = 33 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 38us (kms_flip:3780) DEBUG: name = flip last_ts = 195.274826 last_received_ts = 195.274185 last_seq = 1731 current_ts = 195.291489 current_received_ts = 195.290955 current_seq = 1732 count = 34 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 77us (kms_flip:3780) DEBUG: name = flip last_ts = 195.291489 last_received_ts = 195.290955 last_seq = 1732 current_ts = 195.308151 current_received_ts = 195.307510 current_seq = 1733 count = 35 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 81us (kms_flip:3780) DEBUG: name = flip last_ts = 195.308151 last_received_ts = 195.307510 last_seq = 1733 current_ts = 195.324814 current_received_ts = 195.324295 current_seq = 1734 count = 36 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 119us (kms_flip:3780) DEBUG: name = flip last_ts = 195.324814 last_received_ts = 195.324295 last_seq = 1734 current_ts = 195.341476 current_received_ts = 195.340805 current_seq = 1735 count = 37 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 53us (kms_flip:3780) DEBUG: name = flip last_ts = 195.341476 last_received_ts = 195.340805 last_seq = 1735 current_ts = 195.358154 current_received_ts = 195.357452 current_seq = 1736 count = 38 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 48us (kms_flip:3780) DEBUG: name = flip last_ts = 195.358154 last_received_ts = 195.357452 last_seq = 1736 current_ts = 195.374802 current_received_ts = 195.374130 current_seq = 1737 count = 39 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 195.374802 last_received_ts = 195.374130 last_seq = 1737 current_ts = 195.391479 current_received_ts = 195.390701 current_seq = 1738 count = 40 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 49us (kms_flip:3780) DEBUG: name = flip last_ts = 195.391479 last_received_ts = 195.390701 last_seq = 1738 current_ts = 195.408142 current_received_ts = 195.407440 current_seq = 1739 count = 41 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 49us (kms_flip:3780) DEBUG: name = flip last_ts = 195.408142 last_received_ts = 195.407440 last_seq = 1739 current_ts = 195.424805 current_received_ts = 195.424133 current_seq = 1740 count = 42 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 126us (kms_flip:3780) DEBUG: name = flip last_ts = 195.424805 last_received_ts = 195.424133 last_seq = 1740 current_ts = 195.441467 current_received_ts = 195.440674 current_seq = 1741 count = 43 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 44us (kms_flip:3780) DEBUG: name = flip last_ts = 195.441467 last_received_ts = 195.440674 last_seq = 1741 current_ts = 195.458130 current_received_ts = 195.457672 current_seq = 1742 count = 44 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 90us (kms_flip:3780) DEBUG: name = flip last_ts = 195.458130 last_received_ts = 195.457672 last_seq = 1742 current_ts = 195.474792 current_received_ts = 195.474274 current_seq = 1743 count = 45 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 195.474792 last_received_ts = 195.474274 last_seq = 1743 current_ts = 195.491455 current_received_ts = 195.490677 current_seq = 1744 count = 46 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 51us (kms_flip:3780) DEBUG: name = flip last_ts = 195.491455 last_received_ts = 195.490677 last_seq = 1744 current_ts = 195.508133 current_received_ts = 195.507629 current_seq = 1745 count = 47 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 195.508133 last_received_ts = 195.507629 last_seq = 1745 current_ts = 195.524796 current_received_ts = 195.524292 current_seq = 1746 count = 48 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 87us (kms_flip:3780) DEBUG: name = flip last_ts = 195.524796 last_received_ts = 195.524292 last_seq = 1746 current_ts = 195.541458 current_received_ts = 195.540939 current_seq = 1747 count = 49 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 195.541458 last_received_ts = 195.540939 last_seq = 1747 current_ts = 195.558121 current_received_ts = 195.557602 current_seq = 1748 count = 50 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 195.558121 last_received_ts = 195.557602 last_seq = 1748 current_ts = 195.574783 current_received_ts = 195.574127 current_seq = 1749 count = 51 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 39us (kms_flip:3780) DEBUG: name = flip last_ts = 195.574783 last_received_ts = 195.574127 last_seq = 1749 current_ts = 195.591446 current_received_ts = 195.590805 current_seq = 1750 count = 52 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 65us (kms_flip:3780) DEBUG: name = flip last_ts = 195.591446 last_received_ts = 195.590805 last_seq = 1750 current_ts = 195.608109 current_received_ts = 195.607330 current_seq = 1751 count = 53 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 57us (kms_flip:3780) DEBUG: name = flip last_ts = 195.608109 last_received_ts = 195.607330 last_seq = 1751 current_ts = 195.624771 current_received_ts = 195.624283 current_seq = 1752 count = 54 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 38us (kms_flip:3780) DEBUG: name = flip last_ts = 195.624771 last_received_ts = 195.624283 last_seq = 1752 current_ts = 195.641434 current_received_ts = 195.640930 current_seq = 1753 count = 55 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 195.641434 last_received_ts = 195.640930 last_seq = 1753 current_ts = 195.658112 current_received_ts = 195.657547 current_seq = 1754 count = 56 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 195.658112 last_received_ts = 195.657547 last_seq = 1754 current_ts = 195.674759 current_received_ts = 195.674286 current_seq = 1755 count = 57 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 195.674759 last_received_ts = 195.674286 last_seq = 1755 current_ts = 195.691437 current_received_ts = 195.690979 current_seq = 1756 count = 58 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 43us (kms_flip:3780) DEBUG: name = flip last_ts = 195.691437 last_received_ts = 195.690979 last_seq = 1756 current_ts = 195.708099 current_received_ts = 195.707489 current_seq = 1757 count = 59 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 195.708099 last_received_ts = 195.707489 last_seq = 1757 current_ts = 195.724762 current_received_ts = 195.724319 current_seq = 1758 count = 60 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 195.724762 last_received_ts = 195.724319 last_seq = 1758 current_ts = 195.741425 current_received_ts = 195.740952 current_seq = 1759 count = 61 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 195.741425 last_received_ts = 195.740952 last_seq = 1759 current_ts = 195.758087 current_received_ts = 195.757629 current_seq = 1760 count = 62 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 37us (kms_flip:3780) DEBUG: name = flip last_ts = 195.758087 last_received_ts = 195.757629 last_seq = 1760 current_ts = 195.774750 current_received_ts = 195.774292 current_seq = 1761 count = 63 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 195.774750 last_received_ts = 195.774292 last_seq = 1761 current_ts = 195.791412 current_received_ts = 195.790955 current_seq = 1762 count = 64 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 44us (kms_flip:3780) DEBUG: name = flip last_ts = 195.791412 last_received_ts = 195.790955 last_seq = 1762 current_ts = 195.808075 current_received_ts = 195.807465 current_seq = 1763 count = 65 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 42us (kms_flip:3780) DEBUG: name = flip last_ts = 195.808075 last_received_ts = 195.807465 last_seq = 1763 current_ts = 195.824753 current_received_ts = 195.824219 current_seq = 1764 count = 66 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 39us (kms_flip:3780) DEBUG: name = flip last_ts = 195.824753 last_received_ts = 195.824219 last_seq = 1764 current_ts = 195.841415 current_received_ts = 195.840805 current_seq = 1765 count = 67 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 39us (kms_flip:3780) DEBUG: name = flip last_ts = 195.841415 last_received_ts = 195.840805 last_seq = 1765 current_ts = 195.858078 current_received_ts = 195.857635 current_seq = 1766 count = 68 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 195.858078 last_received_ts = 195.857635 last_seq = 1766 current_ts = 195.874741 current_received_ts = 195.874268 current_seq = 1767 count = 69 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 195.874741 last_received_ts = 195.874268 last_seq = 1767 current_ts = 195.891403 current_received_ts = 195.890793 current_seq = 1768 count = 70 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 41us (kms_flip:3780) DEBUG: name = flip last_ts = 195.891403 last_received_ts = 195.890793 last_seq = 1768 current_ts = 195.908066 current_received_ts = 195.907501 current_seq = 1769 count = 71 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 39us (kms_flip:3780) DEBUG: name = flip last_ts = 195.908066 last_received_ts = 195.907501 last_seq = 1769 current_ts = 195.924728 current_received_ts = 195.924286 current_seq = 1770 count = 72 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 195.924728 last_received_ts = 195.924286 last_seq = 1770 current_ts = 195.941391 current_received_ts = 195.940933 current_seq = 1771 count = 73 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 195.941391 last_received_ts = 195.940933 last_seq = 1771 current_ts = 195.958069 current_received_ts = 195.957596 current_seq = 1772 count = 74 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 195.958069 last_received_ts = 195.957596 last_seq = 1772 current_ts = 195.974716 current_received_ts = 195.974258 current_seq = 1773 count = 75 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 195.974716 last_received_ts = 195.974258 last_seq = 1773 current_ts = 195.991394 current_received_ts = 195.990921 current_seq = 1774 count = 76 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 195.991394 last_received_ts = 195.990921 last_seq = 1774 current_ts = 196.008057 current_received_ts = 196.007355 current_seq = 1775 count = 77 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 103us (kms_flip:3780) DEBUG: name = flip last_ts = 196.008057 last_received_ts = 196.007355 last_seq = 1775 current_ts = 196.024719 current_received_ts = 196.023956 current_seq = 1776 count = 78 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 45us (kms_flip:3780) DEBUG: name = flip last_ts = 196.024719 last_received_ts = 196.023956 last_seq = 1776 current_ts = 196.041382 current_received_ts = 196.040619 current_seq = 1777 count = 79 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 50us (kms_flip:3780) DEBUG: name = flip last_ts = 196.041382 last_received_ts = 196.040619 last_seq = 1777 current_ts = 196.058044 current_received_ts = 196.057465 current_seq = 1778 count = 80 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 196.058044 last_received_ts = 196.057465 last_seq = 1778 current_ts = 196.074707 current_received_ts = 196.074295 current_seq = 1779 count = 81 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 30us (kms_flip:3780) DEBUG: name = flip last_ts = 196.074707 last_received_ts = 196.074295 last_seq = 1779 current_ts = 196.091370 current_received_ts = 196.090912 current_seq = 1780 count = 82 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 105us (kms_flip:3780) DEBUG: name = flip last_ts = 196.091370 last_received_ts = 196.090912 last_seq = 1780 current_ts = 196.108032 current_received_ts = 196.107498 current_seq = 1781 count = 83 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 196.108032 last_received_ts = 196.107498 last_seq = 1781 current_ts = 196.124710 current_received_ts = 196.124176 current_seq = 1782 count = 84 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 196.124710 last_received_ts = 196.124176 last_seq = 1782 current_ts = 196.141373 current_received_ts = 196.140915 current_seq = 1783 count = 85 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 196.141373 last_received_ts = 196.140915 last_seq = 1783 current_ts = 196.158035 current_received_ts = 196.157471 current_seq = 1784 count = 86 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 196.158035 last_received_ts = 196.157471 last_seq = 1784 current_ts = 196.174698 current_received_ts = 196.174408 current_seq = 1785 count = 87 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 84us (kms_flip:3780) DEBUG: name = flip last_ts = 196.174698 last_received_ts = 196.174408 last_seq = 1785 current_ts = 196.191360 current_received_ts = 196.190948 current_seq = 1786 count = 88 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 126us (kms_flip:3780) DEBUG: name = flip last_ts = 196.191360 last_received_ts = 196.190948 last_seq = 1786 current_ts = 196.208023 current_received_ts = 196.207428 current_seq = 1787 count = 89 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 70us (kms_flip:3780) DEBUG: name = flip last_ts = 196.208023 last_received_ts = 196.207428 last_seq = 1787 current_ts = 196.224686 current_received_ts = 196.224274 current_seq = 1788 count = 90 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 93us (kms_flip:3780) DEBUG: name = flip last_ts = 196.224686 last_received_ts = 196.224274 last_seq = 1788 current_ts = 196.241348 current_received_ts = 196.240738 current_seq = 1789 count = 91 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 196.241348 last_received_ts = 196.240738 last_seq = 1789 current_ts = 196.258011 current_received_ts = 196.257431 current_seq = 1790 count = 92 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 31us (kms_flip:3780) DEBUG: name = flip last_ts = 196.258011 last_received_ts = 196.257431 last_seq = 1790 current_ts = 196.274673 current_received_ts = 196.274353 current_seq = 1791 count = 93 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 83us (kms_flip:3780) DEBUG: name = flip last_ts = 196.274673 last_received_ts = 196.274353 last_seq = 1791 current_ts = 196.291336 current_received_ts = 196.290909 current_seq = 1792 count = 94 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 106us (kms_flip:3780) DEBUG: name = flip last_ts = 196.291336 last_received_ts = 196.290909 last_seq = 1792 current_ts = 196.308014 current_received_ts = 196.307556 current_seq = 1793 count = 95 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 93us (kms_flip:3780) DEBUG: name = flip last_ts = 196.308014 last_received_ts = 196.307556 last_seq = 1793 current_ts = 196.324677 current_received_ts = 196.324188 current_seq = 1794 count = 96 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 196.324677 last_received_ts = 196.324188 last_seq = 1794 current_ts = 196.341339 current_received_ts = 196.340744 current_seq = 1795 count = 97 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 196.341339 last_received_ts = 196.340744 last_seq = 1795 current_ts = 196.358002 current_received_ts = 196.357544 current_seq = 1796 count = 98 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 84us (kms_flip:3780) DEBUG: name = flip last_ts = 196.358002 last_received_ts = 196.357544 last_seq = 1796 current_ts = 196.374664 current_received_ts = 196.374176 current_seq = 1797 count = 99 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 196.374664 last_received_ts = 196.374176 last_seq = 1797 current_ts = 196.391342 current_received_ts = 196.390869 current_seq = 1798 count = 100 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 196.391342 last_received_ts = 196.390869 last_seq = 1798 current_ts = 196.407990 current_received_ts = 196.407379 current_seq = 1799 count = 101 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 196.407990 last_received_ts = 196.407379 last_seq = 1799 current_ts = 196.424667 current_received_ts = 196.424057 current_seq = 1800 count = 102 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 196.424667 last_received_ts = 196.424057 last_seq = 1800 current_ts = 196.441330 current_received_ts = 196.440704 current_seq = 1801 count = 103 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 196.441330 last_received_ts = 196.440704 last_seq = 1801 current_ts = 196.457993 current_received_ts = 196.457397 current_seq = 1802 count = 104 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 89us (kms_flip:3780) DEBUG: name = flip last_ts = 196.457993 last_received_ts = 196.457397 last_seq = 1802 current_ts = 196.474655 current_received_ts = 196.474213 current_seq = 1803 count = 105 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 196.474655 last_received_ts = 196.474213 last_seq = 1803 current_ts = 196.491318 current_received_ts = 196.490860 current_seq = 1804 count = 106 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 196.491318 last_received_ts = 196.490860 last_seq = 1804 current_ts = 196.507980 current_received_ts = 196.507538 current_seq = 1805 count = 107 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 196.507980 last_received_ts = 196.507538 last_seq = 1805 current_ts = 196.524643 current_received_ts = 196.524170 current_seq = 1806 count = 108 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 196.524643 last_received_ts = 196.524170 last_seq = 1806 current_ts = 196.541306 current_received_ts = 196.540695 current_seq = 1807 count = 109 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 38us (kms_flip:3780) DEBUG: name = flip last_ts = 196.541306 last_received_ts = 196.540695 last_seq = 1807 current_ts = 196.557968 current_received_ts = 196.557404 current_seq = 1808 count = 110 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 38us (kms_flip:3780) DEBUG: name = flip last_ts = 196.557968 last_received_ts = 196.557404 last_seq = 1808 current_ts = 196.574631 current_received_ts = 196.574173 current_seq = 1809 count = 111 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 38us (kms_flip:3780) DEBUG: name = flip last_ts = 196.574631 last_received_ts = 196.574173 last_seq = 1809 current_ts = 196.591293 current_received_ts = 196.590698 current_seq = 1810 count = 112 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 38us (kms_flip:3780) DEBUG: name = flip last_ts = 196.591293 last_received_ts = 196.590698 last_seq = 1810 current_ts = 196.607971 current_received_ts = 196.607346 current_seq = 1811 count = 113 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 196.607971 last_received_ts = 196.607346 last_seq = 1811 current_ts = 196.624634 current_received_ts = 196.624191 current_seq = 1812 count = 114 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 41us (kms_flip:3780) DEBUG: name = flip last_ts = 196.624634 last_received_ts = 196.624191 last_seq = 1812 current_ts = 196.641296 current_received_ts = 196.640701 current_seq = 1813 count = 115 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 93us (kms_flip:3780) DEBUG: name = flip last_ts = 196.641296 last_received_ts = 196.640701 last_seq = 1813 current_ts = 196.657959 current_received_ts = 196.657364 current_seq = 1814 count = 116 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 31us (kms_flip:3780) DEBUG: name = flip last_ts = 196.657959 last_received_ts = 196.657364 last_seq = 1814 current_ts = 196.674622 current_received_ts = 196.674026 current_seq = 1815 count = 117 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 196.674622 last_received_ts = 196.674026 last_seq = 1815 current_ts = 196.691299 current_received_ts = 196.690796 current_seq = 1816 count = 118 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 196.691299 last_received_ts = 196.690796 last_seq = 1816 current_ts = 196.707947 current_received_ts = 196.707352 current_seq = 1817 count = 119 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 196.707947 last_received_ts = 196.707352 last_seq = 1817 current_ts = 196.724609 current_received_ts = 196.724182 current_seq = 1818 count = 120 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 38us (kms_flip:3780) DEBUG: name = flip last_ts = 196.724609 last_received_ts = 196.724182 last_seq = 1818 current_ts = 196.741272 current_received_ts = 196.740829 current_seq = 1819 count = 121 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 196.741272 last_received_ts = 196.740829 last_seq = 1819 current_ts = 196.757950 current_received_ts = 196.757507 current_seq = 1820 count = 122 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 31us (kms_flip:3780) DEBUG: name = flip last_ts = 196.757950 last_received_ts = 196.757507 last_seq = 1820 current_ts = 196.774612 current_received_ts = 196.774124 current_seq = 1821 count = 123 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 31us (kms_flip:3780) DEBUG: name = flip last_ts = 196.774612 last_received_ts = 196.774124 last_seq = 1821 current_ts = 196.791275 current_received_ts = 196.790833 current_seq = 1822 count = 124 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 196.791275 last_received_ts = 196.790833 last_seq = 1822 current_ts = 196.807938 current_received_ts = 196.807327 current_seq = 1823 count = 125 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 106us (kms_flip:3780) DEBUG: name = flip last_ts = 196.807938 last_received_ts = 196.807327 last_seq = 1823 current_ts = 196.824600 current_received_ts = 196.824158 current_seq = 1824 count = 126 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 196.824600 last_received_ts = 196.824158 last_seq = 1824 current_ts = 196.841263 current_received_ts = 196.840790 current_seq = 1825 count = 127 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 196.841263 last_received_ts = 196.840790 last_seq = 1825 current_ts = 196.857941 current_received_ts = 196.857483 current_seq = 1826 count = 128 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 196.857941 last_received_ts = 196.857483 last_seq = 1826 current_ts = 196.874588 current_received_ts = 196.874283 current_seq = 1827 count = 129 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 66us (kms_flip:3780) DEBUG: name = flip last_ts = 196.874588 last_received_ts = 196.874283 last_seq = 1827 current_ts = 196.891266 current_received_ts = 196.890884 current_seq = 1828 count = 130 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 59us (kms_flip:3780) DEBUG: name = flip last_ts = 196.891266 last_received_ts = 196.890884 last_seq = 1828 current_ts = 196.907928 current_received_ts = 196.907501 current_seq = 1829 count = 131 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 196.907928 last_received_ts = 196.907501 last_seq = 1829 current_ts = 196.924591 current_received_ts = 196.924042 current_seq = 1830 count = 132 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 196.924591 last_received_ts = 196.924042 last_seq = 1830 current_ts = 196.941254 current_received_ts = 196.940796 current_seq = 1831 count = 133 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 35us (kms_flip:3780) DEBUG: name = flip last_ts = 196.941254 last_received_ts = 196.940796 last_seq = 1831 current_ts = 196.957916 current_received_ts = 196.957458 current_seq = 1832 count = 134 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 37us (kms_flip:3780) DEBUG: name = flip last_ts = 196.957916 last_received_ts = 196.957458 last_seq = 1832 current_ts = 196.974579 current_received_ts = 196.974106 current_seq = 1833 count = 135 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 196.974579 last_received_ts = 196.974106 last_seq = 1833 current_ts = 196.991241 current_received_ts = 196.990784 current_seq = 1834 count = 136 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 196.991241 last_received_ts = 196.990784 last_seq = 1834 current_ts = 197.007904 current_received_ts = 197.007294 current_seq = 1835 count = 137 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 197.007904 last_received_ts = 197.007294 last_seq = 1835 current_ts = 197.024582 current_received_ts = 197.024109 current_seq = 1836 count = 138 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 34us (kms_flip:3780) DEBUG: name = flip last_ts = 197.024582 last_received_ts = 197.024109 last_seq = 1836 current_ts = 197.041245 current_received_ts = 197.040756 current_seq = 1837 count = 139 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 197.041245 last_received_ts = 197.040756 last_seq = 1837 current_ts = 197.057907 current_received_ts = 197.057449 current_seq = 1838 count = 140 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 37us (kms_flip:3780) DEBUG: name = flip last_ts = 197.057907 last_received_ts = 197.057449 last_seq = 1838 current_ts = 197.074570 current_received_ts = 197.074097 current_seq = 1839 count = 141 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 111us (kms_flip:3780) DEBUG: name = flip last_ts = 197.074570 last_received_ts = 197.074097 last_seq = 1839 current_ts = 197.091232 current_received_ts = 197.090775 current_seq = 1840 count = 142 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 36us (kms_flip:3780) DEBUG: name = flip last_ts = 197.091232 last_received_ts = 197.090775 last_seq = 1840 current_ts = 197.107895 current_received_ts = 197.107437 current_seq = 1841 count = 143 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 197.107895 last_received_ts = 197.107437 last_seq = 1841 current_ts = 197.124557 current_received_ts = 197.124084 current_seq = 1842 count = 144 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 32us (kms_flip:3780) DEBUG: name = flip last_ts = 197.124557 last_received_ts = 197.124084 last_seq = 1842 current_ts = 197.141220 current_received_ts = 197.140762 current_seq = 1843 count = 145 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 31us (kms_flip:3780) DEBUG: name = flip last_ts = 197.141220 last_received_ts = 197.140762 last_seq = 1843 current_ts = 197.157898 current_received_ts = 197.157425 current_seq = 1844 count = 146 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 33us (kms_flip:3780) DEBUG: name = flip last_ts = 197.157898 last_received_ts = 197.157425 last_seq = 1844 current_ts = 197.174561 current_received_ts = 197.174072 current_seq = 1845 count = 147 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 37us (kms_flip:3780) DEBUG: name = flip last_ts = 197.174561 last_received_ts = 197.174072 last_seq = 1845 current_ts = 197.191223 current_received_ts = 197.190903 current_seq = 1846 count = 148 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 105us (kms_flip:3780) DEBUG: name = flip last_ts = 197.191223 last_received_ts = 197.190903 last_seq = 1846 current_ts = 197.207886 current_received_ts = 197.207321 current_seq = 1847 count = 149 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 165us (kms_flip:3780) DEBUG: name = flip last_ts = 197.207886 last_received_ts = 197.207321 last_seq = 1847 current_ts = 197.224548 current_received_ts = 197.223862 current_seq = 1848 count = 150 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 164us (kms_flip:3780) DEBUG: name = flip last_ts = 197.224548 last_received_ts = 197.223862 last_seq = 1848 current_ts = 197.241211 current_received_ts = 197.240433 current_seq = 1849 count = 151 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 91us (kms_flip:3780) DEBUG: name = flip last_ts = 197.241211 last_received_ts = 197.240433 last_seq = 1849 current_ts = 197.257874 current_received_ts = 197.257111 current_seq = 1850 count = 152 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 62us (kms_flip:3780) DEBUG: name = flip last_ts = 197.257874 last_received_ts = 197.257111 last_seq = 1850 current_ts = 197.274536 current_received_ts = 197.273956 current_seq = 1851 count = 153 seq_step = 1 (kms_flip:3780) DEBUG: Vblank took 1641us (kms_flip:3780) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:3780) CRITICAL: Failed assertion: end - start < 500 (kms_flip:3780) igt_core-INFO: Stack trace: (kms_flip:3780) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:3780) igt_core-INFO: #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() (kms_flip:3780) igt_core-INFO: #2 ../tests/kms_flip.c:1887 run_test() (kms_flip:3780) igt_core-INFO: #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043() (kms_flip:3780) igt_core-INFO: #4 ../tests/kms_flip.c:2043 main() (kms_flip:3780) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:3780) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:3780) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (3.913s)
Dmesg	<6> [193.507912] Console: switching to colour dummy device 80x25 <6> [193.508099] [IGT] kms_flip: executing <7> [193.513215] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] <7> [193.513224] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1] <7> [193.513401] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected <7> [193.513656] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] <7> [193.513658] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2] <7> [193.513786] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected <7> [193.514009] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] <7> [193.514010] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3] <7> [193.514124] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected <7> [193.514424] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] <7> [193.514428] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:392:eDP-1] <7> [193.514891] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00 <7> [193.515212] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [193.515324] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [193.515432] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [193.515544] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz <5> [193.515549] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [193.515550] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [193.515551] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] DisplayID extension version 0x13, primary use 0x00 <7> [193.515553] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <5> [193.515555] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [193.515556] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD monitor <5> [193.515558] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [193.515559] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD size 20, SAD count 0 <5> [193.515561] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [193.515570] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] VRR capable: yes <7> [193.515649] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [193.515727] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <5> [193.516231] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [193.516233] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [193.516234] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [193.516292] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] probed modes: <7> [193.516295] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [193.516299] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [193.516311] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] <7> [193.516314] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1] <7> [193.516459] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected <7> [193.516470] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] <7> [193.516472] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2] <7> [193.516589] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected <7> [193.516595] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] <7> [193.516597] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3] <7> [193.516698] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected <6> [193.517061] [IGT] kms_flip: starting subtest flip-vs-expired-vblank <6> [193.518377] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [193.530443] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:428] <7> [193.530832] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:431] <7> [193.602132] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [193.602445] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [193.602911] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [193.603183] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [193.603449] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [193.603672] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150: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> [193.603882] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [193.604088] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [193.604332] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [193.604524] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [193.604713] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [193.604902] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [193.605121] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [193.605334] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [193.605502] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [193.605668] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [193.605834] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [193.605993] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [193.606149] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [193.606342] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [193.606502] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [193.606642] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [193.606775] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [193.606908] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [193.607059] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [193.607219] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [193.607352] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [193.607473] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [193.607592] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [193.607728] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [193.607868] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [193.607989] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [193.608103] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [193.608223] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [193.608333] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [193.608444] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [193.608550] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [193.608654] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [193.608757] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 432000, found 0) <7> [193.608865] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset <7> [193.608973] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:150:pipe A] releasing DPLL 0 <7> [193.609138] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [193.609254] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [193.609365] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [193.609444] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [193.609522] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [193.609597] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [193.609669] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [193.609739] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [193.609829] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 0 num active planes 0 <7> [193.609941] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [193.610048] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [193.610150] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [193.610268] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [193.610384] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [193.610504] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [193.610640] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [193.610737] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [193.610832] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [193.610924] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [193.611043] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: no [modeset] <7> [193.611147] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [NOFB], visible: no <7> [193.611273] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no <7> [193.611385] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no <7> [193.611487] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no <7> [193.611573] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no <7> [193.611656] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no <7> [193.611784] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [193.612515] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [193.612661] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [193.613375] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [193.613489] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [193.821377] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 0 <7> [193.822044] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [193.832725] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power off <7> [193.833085] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power off time <7> [193.833492] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [193.885490] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [193.885989] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short <7> [193.894680] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [193.895238] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [193.895240] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:150:pipe A] <7> [193.896801] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [193.897291] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [193.897834] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A] <7> [193.898172] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1] <7> [193.898546] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A] <7> [193.898848] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B] <7> [193.899249] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C] <7> [193.899570] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2] <7> [193.899854] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A] <7> [193.900133] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B] <7> [193.900485] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C] <7> [193.900760] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3] <7> [193.901030] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A] <7> [193.901331] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B] <7> [193.901599] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C] <7> [193.901904] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1] <7> [193.902326] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [193.902629] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [193.902914] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [193.903412] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [193.903808] 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> [193.904368] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A] <7> [193.904716] 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> [193.905153] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [193.905519] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [193.906452] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B] <7> [193.906837] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:388:pipe C] <7> [193.907160] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [193.907252] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:392:eDP-1] <7> [193.907444] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:392:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [193.907861] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:391:DDI A/PHY A][CRTC:150:pipe A] 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> [193.908208] 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> [193.908581] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [193.908908] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:391:DDI A/PHY A] [CRTC:150:pipe A] <7> [193.909242] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [193.909548] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [193.909882] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [193.910160] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [193.910462] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] 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> [193.910709] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [193.910936] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [193.911159] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [193.911416] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [193.911624] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880) <7> [193.911820] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040) <7> [193.912013] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928) <7> [193.912207] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960) <7> [193.912390] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [193.912566] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800) <7> [193.912739] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803) <7> [193.912910] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809) <7> [193.913072] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [193.913242] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906) <7> [193.913397] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [193.913552] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [193.913698] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880) <7> [193.913844] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040) <7> [193.913988] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928) <7> [193.914127] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960) <7> [193.914311] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [193.914471] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800) <7> [193.914617] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803) <7> [193.914751] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809) <7> [193.914883] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [193.915013] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906) <7> [193.915137] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [193.915272] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [193.915389] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [193.915503] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [193.915614] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [193.915725] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [193.915836] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 432000) <7> [193.915946] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset <7> [193.916093] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [193.916175] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [193.916306] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [193.916386] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [193.916463] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [193.916537] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 <7> [193.916608] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 <7> [193.916686] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] 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> [193.916788] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 1390840 num active planes 1 <7> [193.916901] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [193.917008] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [193.917107] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [193.917208] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [193.917312] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [193.917425] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 173855 kHz <7> [193.917555] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [193.917654] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [193.917742] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [193.917829] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [193.917926] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated DPLL 0 <7> [193.918017] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving DPLL 0 <7> [193.918109] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset] <7> [193.918202] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [193.918304] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0 <7> [193.918403] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [193.918500] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [193.918592] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [193.918666] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [193.918739] 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> [193.918811] 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> [193.918882] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [193.918953] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [193.919023] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [193.919094] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0 <7> [193.919164] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [193.919270] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [193.919364] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [193.919458] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [193.919550] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [193.919629] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [193.919700] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [193.919772] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [193.919843] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [193.919915] 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> [193.919987] 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> [193.920059] 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> [193.920131] 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> [193.920211] 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> [193.920305] 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> [193.920408] 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> [193.920514] 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> [193.920602] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855 <7> [193.920680] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [193.920754] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [193.920828] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [193.920901] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [193.920973] 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> [193.921046] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no, <7> [193.921118] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1. <7> [193.921196] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [193.921283] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [193.921374] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1 <7> [193.921465] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [193.921554] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [193.921625] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [193.921693] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23 <7> [193.921761] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [193.921830] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [193.921898] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [193.921967] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [193.922034] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [193.922103] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [193.922171] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [193.922270] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [193.922370] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [193.922475] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [193.922576] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [193.922666] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [193.922747] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [193.922816] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [FB:428] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [193.922885] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [193.922952] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [193.923023] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no <7> [193.923093] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no <7> [193.923162] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no <7> [193.923251] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no <7> [193.923200] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [193.923352] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no <7> [193.923382] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long <7> [193.923474] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [193.923584] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [193.923769] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [193.923919] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000) <7> [193.924015] 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> [193.924101] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [193.924195] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [193.924295] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A] <7> [193.924382] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1] <7> [193.924468] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A] <7> [193.924544] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B] <7> [193.924608] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C] <7> [193.924673] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2] <7> [193.924737] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A] <7> [193.924801] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B] <7> [193.924863] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C] <7> [193.924925] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3] <7> [193.924986] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A] <7> [193.925046] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B] <7> [193.925106] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C] <7> [193.925194] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [193.925372] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [193.925450] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [193.925570] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [193.926312] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:150:pipe A] <7> [193.926451] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [193.928418] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power on <7> [193.928514] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining) <7> [194.397648] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [194.455527] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [194.455963] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power on <7> [194.456412] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [194.492849] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [194.493355] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long <7> [194.493738] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [194.494254] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [194.573390] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [194.573471] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [194.573596] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [194.668709] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [194.669094] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on <7> [194.669500] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [194.671622] 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> [194.673190] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [194.673990] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05 <7> [194.675126] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [194.676533] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [194.677626] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Clock recovery OK <7> [194.677969] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [194.679478] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [194.679821] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4 <7> [194.680674] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [194.681159] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [194.681580] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [194.681984] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 4518 <7> [194.698037] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [194.699815] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1] <7> [194.700247] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A] <7> [197.261256] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD off <7> [197.261983] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067 <7> [197.298192] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [197.298710] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [197.299081] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [197.432333] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

3.91 seconds

Hostname

shard-lnl-5

Igt-Version

IGT-Version: 2.3-g07ca77c0e (x86_64) (Linux: 6.19.0-lgci-xe-xe-4557-0558a31efefc20e30-debug+ x86_64)

Out

Using IGT_SRANDOM=1771100265 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-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:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (3.913s)

Err

Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
(kms_flip:3780) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:3780) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.241501
last_received_ts = 195.240814
last_seq = 1729
current_ts = 195.258163
current_received_ts = 195.257477
current_seq = 1730
count = 32
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 109us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.258163
last_received_ts = 195.257477
last_seq = 1730
current_ts = 195.274826
current_received_ts = 195.274185
current_seq = 1731
count = 33
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 38us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.274826
last_received_ts = 195.274185
last_seq = 1731
current_ts = 195.291489
current_received_ts = 195.290955
current_seq = 1732
count = 34
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 77us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.291489
last_received_ts = 195.290955
last_seq = 1732
current_ts = 195.308151
current_received_ts = 195.307510
current_seq = 1733
count = 35
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 81us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.308151
last_received_ts = 195.307510
last_seq = 1733
current_ts = 195.324814
current_received_ts = 195.324295
current_seq = 1734
count = 36
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 119us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.324814
last_received_ts = 195.324295
last_seq = 1734
current_ts = 195.341476
current_received_ts = 195.340805
current_seq = 1735
count = 37
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 53us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.341476
last_received_ts = 195.340805
last_seq = 1735
current_ts = 195.358154
current_received_ts = 195.357452
current_seq = 1736
count = 38
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 48us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.358154
last_received_ts = 195.357452
last_seq = 1736
current_ts = 195.374802
current_received_ts = 195.374130
current_seq = 1737
count = 39
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.374802
last_received_ts = 195.374130
last_seq = 1737
current_ts = 195.391479
current_received_ts = 195.390701
current_seq = 1738
count = 40
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 49us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.391479
last_received_ts = 195.390701
last_seq = 1738
current_ts = 195.408142
current_received_ts = 195.407440
current_seq = 1739
count = 41
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 49us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.408142
last_received_ts = 195.407440
last_seq = 1739
current_ts = 195.424805
current_received_ts = 195.424133
current_seq = 1740
count = 42
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 126us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.424805
last_received_ts = 195.424133
last_seq = 1740
current_ts = 195.441467
current_received_ts = 195.440674
current_seq = 1741
count = 43
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 44us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.441467
last_received_ts = 195.440674
last_seq = 1741
current_ts = 195.458130
current_received_ts = 195.457672
current_seq = 1742
count = 44
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 90us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.458130
last_received_ts = 195.457672
last_seq = 1742
current_ts = 195.474792
current_received_ts = 195.474274
current_seq = 1743
count = 45
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.474792
last_received_ts = 195.474274
last_seq = 1743
current_ts = 195.491455
current_received_ts = 195.490677
current_seq = 1744
count = 46
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 51us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.491455
last_received_ts = 195.490677
last_seq = 1744
current_ts = 195.508133
current_received_ts = 195.507629
current_seq = 1745
count = 47
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.508133
last_received_ts = 195.507629
last_seq = 1745
current_ts = 195.524796
current_received_ts = 195.524292
current_seq = 1746
count = 48
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 87us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.524796
last_received_ts = 195.524292
last_seq = 1746
current_ts = 195.541458
current_received_ts = 195.540939
current_seq = 1747
count = 49
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.541458
last_received_ts = 195.540939
last_seq = 1747
current_ts = 195.558121
current_received_ts = 195.557602
current_seq = 1748
count = 50
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.558121
last_received_ts = 195.557602
last_seq = 1748
current_ts = 195.574783
current_received_ts = 195.574127
current_seq = 1749
count = 51
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 39us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.574783
last_received_ts = 195.574127
last_seq = 1749
current_ts = 195.591446
current_received_ts = 195.590805
current_seq = 1750
count = 52
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 65us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.591446
last_received_ts = 195.590805
last_seq = 1750
current_ts = 195.608109
current_received_ts = 195.607330
current_seq = 1751
count = 53
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 57us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.608109
last_received_ts = 195.607330
last_seq = 1751
current_ts = 195.624771
current_received_ts = 195.624283
current_seq = 1752
count = 54
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 38us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.624771
last_received_ts = 195.624283
last_seq = 1752
current_ts = 195.641434
current_received_ts = 195.640930
current_seq = 1753
count = 55
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.641434
last_received_ts = 195.640930
last_seq = 1753
current_ts = 195.658112
current_received_ts = 195.657547
current_seq = 1754
count = 56
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.658112
last_received_ts = 195.657547
last_seq = 1754
current_ts = 195.674759
current_received_ts = 195.674286
current_seq = 1755
count = 57
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.674759
last_received_ts = 195.674286
last_seq = 1755
current_ts = 195.691437
current_received_ts = 195.690979
current_seq = 1756
count = 58
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 43us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.691437
last_received_ts = 195.690979
last_seq = 1756
current_ts = 195.708099
current_received_ts = 195.707489
current_seq = 1757
count = 59
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.708099
last_received_ts = 195.707489
last_seq = 1757
current_ts = 195.724762
current_received_ts = 195.724319
current_seq = 1758
count = 60
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.724762
last_received_ts = 195.724319
last_seq = 1758
current_ts = 195.741425
current_received_ts = 195.740952
current_seq = 1759
count = 61
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.741425
last_received_ts = 195.740952
last_seq = 1759
current_ts = 195.758087
current_received_ts = 195.757629
current_seq = 1760
count = 62
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 37us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.758087
last_received_ts = 195.757629
last_seq = 1760
current_ts = 195.774750
current_received_ts = 195.774292
current_seq = 1761
count = 63
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.774750
last_received_ts = 195.774292
last_seq = 1761
current_ts = 195.791412
current_received_ts = 195.790955
current_seq = 1762
count = 64
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 44us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.791412
last_received_ts = 195.790955
last_seq = 1762
current_ts = 195.808075
current_received_ts = 195.807465
current_seq = 1763
count = 65
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 42us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.808075
last_received_ts = 195.807465
last_seq = 1763
current_ts = 195.824753
current_received_ts = 195.824219
current_seq = 1764
count = 66
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 39us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.824753
last_received_ts = 195.824219
last_seq = 1764
current_ts = 195.841415
current_received_ts = 195.840805
current_seq = 1765
count = 67
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 39us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.841415
last_received_ts = 195.840805
last_seq = 1765
current_ts = 195.858078
current_received_ts = 195.857635
current_seq = 1766
count = 68
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.858078
last_received_ts = 195.857635
last_seq = 1766
current_ts = 195.874741
current_received_ts = 195.874268
current_seq = 1767
count = 69
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.874741
last_received_ts = 195.874268
last_seq = 1767
current_ts = 195.891403
current_received_ts = 195.890793
current_seq = 1768
count = 70
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 41us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.891403
last_received_ts = 195.890793
last_seq = 1768
current_ts = 195.908066
current_received_ts = 195.907501
current_seq = 1769
count = 71
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 39us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.908066
last_received_ts = 195.907501
last_seq = 1769
current_ts = 195.924728
current_received_ts = 195.924286
current_seq = 1770
count = 72
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.924728
last_received_ts = 195.924286
last_seq = 1770
current_ts = 195.941391
current_received_ts = 195.940933
current_seq = 1771
count = 73
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.941391
last_received_ts = 195.940933
last_seq = 1771
current_ts = 195.958069
current_received_ts = 195.957596
current_seq = 1772
count = 74
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.958069
last_received_ts = 195.957596
last_seq = 1772
current_ts = 195.974716
current_received_ts = 195.974258
current_seq = 1773
count = 75
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.974716
last_received_ts = 195.974258
last_seq = 1773
current_ts = 195.991394
current_received_ts = 195.990921
current_seq = 1774
count = 76
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 195.991394
last_received_ts = 195.990921
last_seq = 1774
current_ts = 196.008057
current_received_ts = 196.007355
current_seq = 1775
count = 77
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 103us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.008057
last_received_ts = 196.007355
last_seq = 1775
current_ts = 196.024719
current_received_ts = 196.023956
current_seq = 1776
count = 78
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 45us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.024719
last_received_ts = 196.023956
last_seq = 1776
current_ts = 196.041382
current_received_ts = 196.040619
current_seq = 1777
count = 79
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 50us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.041382
last_received_ts = 196.040619
last_seq = 1777
current_ts = 196.058044
current_received_ts = 196.057465
current_seq = 1778
count = 80
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.058044
last_received_ts = 196.057465
last_seq = 1778
current_ts = 196.074707
current_received_ts = 196.074295
current_seq = 1779
count = 81
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 30us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.074707
last_received_ts = 196.074295
last_seq = 1779
current_ts = 196.091370
current_received_ts = 196.090912
current_seq = 1780
count = 82
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 105us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.091370
last_received_ts = 196.090912
last_seq = 1780
current_ts = 196.108032
current_received_ts = 196.107498
current_seq = 1781
count = 83
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.108032
last_received_ts = 196.107498
last_seq = 1781
current_ts = 196.124710
current_received_ts = 196.124176
current_seq = 1782
count = 84
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.124710
last_received_ts = 196.124176
last_seq = 1782
current_ts = 196.141373
current_received_ts = 196.140915
current_seq = 1783
count = 85
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.141373
last_received_ts = 196.140915
last_seq = 1783
current_ts = 196.158035
current_received_ts = 196.157471
current_seq = 1784
count = 86
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.158035
last_received_ts = 196.157471
last_seq = 1784
current_ts = 196.174698
current_received_ts = 196.174408
current_seq = 1785
count = 87
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 84us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.174698
last_received_ts = 196.174408
last_seq = 1785
current_ts = 196.191360
current_received_ts = 196.190948
current_seq = 1786
count = 88
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 126us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.191360
last_received_ts = 196.190948
last_seq = 1786
current_ts = 196.208023
current_received_ts = 196.207428
current_seq = 1787
count = 89
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 70us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.208023
last_received_ts = 196.207428
last_seq = 1787
current_ts = 196.224686
current_received_ts = 196.224274
current_seq = 1788
count = 90
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 93us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.224686
last_received_ts = 196.224274
last_seq = 1788
current_ts = 196.241348
current_received_ts = 196.240738
current_seq = 1789
count = 91
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.241348
last_received_ts = 196.240738
last_seq = 1789
current_ts = 196.258011
current_received_ts = 196.257431
current_seq = 1790
count = 92
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 31us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.258011
last_received_ts = 196.257431
last_seq = 1790
current_ts = 196.274673
current_received_ts = 196.274353
current_seq = 1791
count = 93
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 83us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.274673
last_received_ts = 196.274353
last_seq = 1791
current_ts = 196.291336
current_received_ts = 196.290909
current_seq = 1792
count = 94
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 106us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.291336
last_received_ts = 196.290909
last_seq = 1792
current_ts = 196.308014
current_received_ts = 196.307556
current_seq = 1793
count = 95
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 93us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.308014
last_received_ts = 196.307556
last_seq = 1793
current_ts = 196.324677
current_received_ts = 196.324188
current_seq = 1794
count = 96
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.324677
last_received_ts = 196.324188
last_seq = 1794
current_ts = 196.341339
current_received_ts = 196.340744
current_seq = 1795
count = 97
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.341339
last_received_ts = 196.340744
last_seq = 1795
current_ts = 196.358002
current_received_ts = 196.357544
current_seq = 1796
count = 98
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 84us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.358002
last_received_ts = 196.357544
last_seq = 1796
current_ts = 196.374664
current_received_ts = 196.374176
current_seq = 1797
count = 99
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.374664
last_received_ts = 196.374176
last_seq = 1797
current_ts = 196.391342
current_received_ts = 196.390869
current_seq = 1798
count = 100
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.391342
last_received_ts = 196.390869
last_seq = 1798
current_ts = 196.407990
current_received_ts = 196.407379
current_seq = 1799
count = 101
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.407990
last_received_ts = 196.407379
last_seq = 1799
current_ts = 196.424667
current_received_ts = 196.424057
current_seq = 1800
count = 102
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.424667
last_received_ts = 196.424057
last_seq = 1800
current_ts = 196.441330
current_received_ts = 196.440704
current_seq = 1801
count = 103
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.441330
last_received_ts = 196.440704
last_seq = 1801
current_ts = 196.457993
current_received_ts = 196.457397
current_seq = 1802
count = 104
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 89us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.457993
last_received_ts = 196.457397
last_seq = 1802
current_ts = 196.474655
current_received_ts = 196.474213
current_seq = 1803
count = 105
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.474655
last_received_ts = 196.474213
last_seq = 1803
current_ts = 196.491318
current_received_ts = 196.490860
current_seq = 1804
count = 106
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.491318
last_received_ts = 196.490860
last_seq = 1804
current_ts = 196.507980
current_received_ts = 196.507538
current_seq = 1805
count = 107
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.507980
last_received_ts = 196.507538
last_seq = 1805
current_ts = 196.524643
current_received_ts = 196.524170
current_seq = 1806
count = 108
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.524643
last_received_ts = 196.524170
last_seq = 1806
current_ts = 196.541306
current_received_ts = 196.540695
current_seq = 1807
count = 109
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 38us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.541306
last_received_ts = 196.540695
last_seq = 1807
current_ts = 196.557968
current_received_ts = 196.557404
current_seq = 1808
count = 110
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 38us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.557968
last_received_ts = 196.557404
last_seq = 1808
current_ts = 196.574631
current_received_ts = 196.574173
current_seq = 1809
count = 111
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 38us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.574631
last_received_ts = 196.574173
last_seq = 1809
current_ts = 196.591293
current_received_ts = 196.590698
current_seq = 1810
count = 112
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 38us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.591293
last_received_ts = 196.590698
last_seq = 1810
current_ts = 196.607971
current_received_ts = 196.607346
current_seq = 1811
count = 113
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.607971
last_received_ts = 196.607346
last_seq = 1811
current_ts = 196.624634
current_received_ts = 196.624191
current_seq = 1812
count = 114
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 41us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.624634
last_received_ts = 196.624191
last_seq = 1812
current_ts = 196.641296
current_received_ts = 196.640701
current_seq = 1813
count = 115
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 93us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.641296
last_received_ts = 196.640701
last_seq = 1813
current_ts = 196.657959
current_received_ts = 196.657364
current_seq = 1814
count = 116
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 31us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.657959
last_received_ts = 196.657364
last_seq = 1814
current_ts = 196.674622
current_received_ts = 196.674026
current_seq = 1815
count = 117
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.674622
last_received_ts = 196.674026
last_seq = 1815
current_ts = 196.691299
current_received_ts = 196.690796
current_seq = 1816
count = 118
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.691299
last_received_ts = 196.690796
last_seq = 1816
current_ts = 196.707947
current_received_ts = 196.707352
current_seq = 1817
count = 119
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.707947
last_received_ts = 196.707352
last_seq = 1817
current_ts = 196.724609
current_received_ts = 196.724182
current_seq = 1818
count = 120
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 38us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.724609
last_received_ts = 196.724182
last_seq = 1818
current_ts = 196.741272
current_received_ts = 196.740829
current_seq = 1819
count = 121
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.741272
last_received_ts = 196.740829
last_seq = 1819
current_ts = 196.757950
current_received_ts = 196.757507
current_seq = 1820
count = 122
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 31us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.757950
last_received_ts = 196.757507
last_seq = 1820
current_ts = 196.774612
current_received_ts = 196.774124
current_seq = 1821
count = 123
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 31us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.774612
last_received_ts = 196.774124
last_seq = 1821
current_ts = 196.791275
current_received_ts = 196.790833
current_seq = 1822
count = 124
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.791275
last_received_ts = 196.790833
last_seq = 1822
current_ts = 196.807938
current_received_ts = 196.807327
current_seq = 1823
count = 125
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 106us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.807938
last_received_ts = 196.807327
last_seq = 1823
current_ts = 196.824600
current_received_ts = 196.824158
current_seq = 1824
count = 126
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.824600
last_received_ts = 196.824158
last_seq = 1824
current_ts = 196.841263
current_received_ts = 196.840790
current_seq = 1825
count = 127
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.841263
last_received_ts = 196.840790
last_seq = 1825
current_ts = 196.857941
current_received_ts = 196.857483
current_seq = 1826
count = 128
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.857941
last_received_ts = 196.857483
last_seq = 1826
current_ts = 196.874588
current_received_ts = 196.874283
current_seq = 1827
count = 129
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 66us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.874588
last_received_ts = 196.874283
last_seq = 1827
current_ts = 196.891266
current_received_ts = 196.890884
current_seq = 1828
count = 130
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 59us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.891266
last_received_ts = 196.890884
last_seq = 1828
current_ts = 196.907928
current_received_ts = 196.907501
current_seq = 1829
count = 131
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.907928
last_received_ts = 196.907501
last_seq = 1829
current_ts = 196.924591
current_received_ts = 196.924042
current_seq = 1830
count = 132
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.924591
last_received_ts = 196.924042
last_seq = 1830
current_ts = 196.941254
current_received_ts = 196.940796
current_seq = 1831
count = 133
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 35us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.941254
last_received_ts = 196.940796
last_seq = 1831
current_ts = 196.957916
current_received_ts = 196.957458
current_seq = 1832
count = 134
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 37us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.957916
last_received_ts = 196.957458
last_seq = 1832
current_ts = 196.974579
current_received_ts = 196.974106
current_seq = 1833
count = 135
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.974579
last_received_ts = 196.974106
last_seq = 1833
current_ts = 196.991241
current_received_ts = 196.990784
current_seq = 1834
count = 136
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 196.991241
last_received_ts = 196.990784
last_seq = 1834
current_ts = 197.007904
current_received_ts = 197.007294
current_seq = 1835
count = 137
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.007904
last_received_ts = 197.007294
last_seq = 1835
current_ts = 197.024582
current_received_ts = 197.024109
current_seq = 1836
count = 138
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 34us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.024582
last_received_ts = 197.024109
last_seq = 1836
current_ts = 197.041245
current_received_ts = 197.040756
current_seq = 1837
count = 139
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.041245
last_received_ts = 197.040756
last_seq = 1837
current_ts = 197.057907
current_received_ts = 197.057449
current_seq = 1838
count = 140
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 37us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.057907
last_received_ts = 197.057449
last_seq = 1838
current_ts = 197.074570
current_received_ts = 197.074097
current_seq = 1839
count = 141
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 111us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.074570
last_received_ts = 197.074097
last_seq = 1839
current_ts = 197.091232
current_received_ts = 197.090775
current_seq = 1840
count = 142
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 36us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.091232
last_received_ts = 197.090775
last_seq = 1840
current_ts = 197.107895
current_received_ts = 197.107437
current_seq = 1841
count = 143
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.107895
last_received_ts = 197.107437
last_seq = 1841
current_ts = 197.124557
current_received_ts = 197.124084
current_seq = 1842
count = 144
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 32us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.124557
last_received_ts = 197.124084
last_seq = 1842
current_ts = 197.141220
current_received_ts = 197.140762
current_seq = 1843
count = 145
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 31us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.141220
last_received_ts = 197.140762
last_seq = 1843
current_ts = 197.157898
current_received_ts = 197.157425
current_seq = 1844
count = 146
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 33us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.157898
last_received_ts = 197.157425
last_seq = 1844
current_ts = 197.174561
current_received_ts = 197.174072
current_seq = 1845
count = 147
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 37us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.174561
last_received_ts = 197.174072
last_seq = 1845
current_ts = 197.191223
current_received_ts = 197.190903
current_seq = 1846
count = 148
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 105us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.191223
last_received_ts = 197.190903
last_seq = 1846
current_ts = 197.207886
current_received_ts = 197.207321
current_seq = 1847
count = 149
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 165us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.207886
last_received_ts = 197.207321
last_seq = 1847
current_ts = 197.224548
current_received_ts = 197.223862
current_seq = 1848
count = 150
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 164us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.224548
last_received_ts = 197.223862
last_seq = 1848
current_ts = 197.241211
current_received_ts = 197.240433
current_seq = 1849
count = 151
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 91us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.241211
last_received_ts = 197.240433
last_seq = 1849
current_ts = 197.257874
current_received_ts = 197.257111
current_seq = 1850
count = 152
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 62us
(kms_flip:3780) DEBUG: name = flip
last_ts = 197.257874
last_received_ts = 197.257111
last_seq = 1850
current_ts = 197.274536
current_received_ts = 197.273956
current_seq = 1851
count = 153
seq_step = 1
(kms_flip:3780) DEBUG: Vblank took 1641us
(kms_flip:3780) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:3780) CRITICAL: Failed assertion: end - start < 500
(kms_flip:3780) igt_core-INFO: Stack trace:
(kms_flip:3780) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:3780) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:3780) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:3780) igt_core-INFO:   #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043()
(kms_flip:3780) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:3780) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:3780) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:3780) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (3.913s)

Dmesg

<6> [193.507912] Console: switching to colour dummy device 80x25

<6> [193.508099] [IGT] kms_flip: executing

<7> [193.513215] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1]

<7> [193.513224] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1]

<7> [193.513401] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected

<7> [193.513656] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2]

<7> [193.513658] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2]

<7> [193.513786] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected

<7> [193.514009] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3]

<7> [193.514010] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3]

<7> [193.514124] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected

<7> [193.514424] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1]

<7> [193.514428] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:392:eDP-1]

<7> [193.514891] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00

<7> [193.515212] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000

<7> [193.515324] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000

<7> [193.515432] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000

<7> [193.515544] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz

<5> [193.515549] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [193.515550] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [193.515551] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] DisplayID extension version 0x13, primary use 0x00

<7> [193.515553] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc.

<5> [193.515555] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [193.515556] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD monitor

<5> [193.515558] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [193.515559] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD size 20, SAD count 0

<5> [193.515561] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [193.515570] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] VRR capable: yes

<7> [193.515649] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps

<7> [193.515727] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no

<5> [193.516231] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [193.516233] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [193.516234] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [193.516292] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] probed modes:

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

<7> [193.516299] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa

<7> [193.516311] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1]

<7> [193.516314] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1]

<7> [193.516459] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected

<7> [193.516470] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2]

<7> [193.516472] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2]

<7> [193.516589] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected

<7> [193.516595] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3]

<7> [193.516597] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3]

<7> [193.516698] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected

<6> [193.517061] [IGT] kms_flip: starting subtest flip-vs-expired-vblank

<6> [193.518377] [IGT] kms_flip: starting dynamic subtest A-eDP1

<7> [193.530443] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:428]

<7> [193.530832] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:431]

<7> [193.602132] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

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

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

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

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

<7> [193.603672] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150: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> [193.603882] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [193.609365] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0

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

<7> [193.609522] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [193.609597] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [193.609669] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [193.609739] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [193.903808] 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> [193.904368] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A]

<7> [193.904716] 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> [193.905153] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

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

<7> [193.906452] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]

<7> [193.906837] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:388:pipe C]

<7> [193.907160] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

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

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

<7> [193.907861] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:391:DDI A/PHY A][CRTC:150:pipe A] 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> [193.908208] 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> [193.908581] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0

<7> [193.908908] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:391:DDI A/PHY A] [CRTC:150:pipe A]

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

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

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

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

<7> [193.910462] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] 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> [193.910709] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [193.916306] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051

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

<7> [193.916463] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34: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> [193.916537] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0

<7> [193.916608] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197

<7> [193.916686] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] 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> [193.916788] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 1390840 num active planes 1

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

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

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

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

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

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

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

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

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

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

<7> [193.917926] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated DPLL 0

<7> [193.918017] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving DPLL 0

<7> [193.918109] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset]

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

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

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

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

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

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

<7> [193.918739] 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> [193.918811] 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> [193.918882] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled

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

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

<7> [193.919094] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0

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

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

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

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

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

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

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

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

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

<7> [193.919915] 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> [193.919987] 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> [193.920059] 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> [193.920131] 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> [193.920211] 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> [193.920305] 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> [193.920408] 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> [193.920514] 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> [193.920602] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855

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

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

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

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

<7> [193.920973] 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> [193.921046] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [193.923769] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A

<7> [193.923919] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)

<7> [193.924015] 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> [193.924101] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [194.573390] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

<7> [194.573471] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

<7> [194.573596] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

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

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

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

<7> [194.671622] 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> [194.673190] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Reloading eDP link rates

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

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

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

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

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

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

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

<7> [194.680674] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A

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

<7> [194.681580] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A

<7> [194.681984] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 4518

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

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

<7> [194.700247] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A]

<7> [197.261256] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD off

<7> [197.261983] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067

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

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

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

<6> [197.432333] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Results for igt@kms_flip@flip-vs-expired-vblank@a-edp1