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

Detail	Value
Duration	3.72 seconds
Hostname	shard-glk2
Igt-Version	IGT-Version: 2.4-ge3bf68535 (x86_64) (Linux: 7.1.0-rc2-CI_DRM_18409-g9160312bed53+ x86_64)
Out	Starting dynamic subtest: B-HDMI-A2 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest B-HDMI-A2: FAIL (3.719s)
Err	Starting dynamic subtest: B-HDMI-A2 (kms_flip:2394) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2394) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2394) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest B-HDMI-A2 failed. ** DEBUG (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.341736 last_received_ts = 316.341431 last_seq = 6730 current_ts = 316.358398 current_received_ts = 316.358337 current_seq = 6731 count = 70 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.358398 last_received_ts = 316.358337 last_seq = 6731 current_ts = 316.375061 current_received_ts = 316.374634 current_seq = 6732 count = 71 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.375061 last_received_ts = 316.374634 last_seq = 6732 current_ts = 316.391724 current_received_ts = 316.391479 current_seq = 6733 count = 72 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.391724 last_received_ts = 316.391479 last_seq = 6733 current_ts = 316.408417 current_received_ts = 316.408142 current_seq = 6734 count = 73 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.408417 last_received_ts = 316.408142 last_seq = 6734 current_ts = 316.425079 current_received_ts = 316.424622 current_seq = 6735 count = 74 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 316.425079 last_received_ts = 316.424622 last_seq = 6735 current_ts = 316.441742 current_received_ts = 316.441772 current_seq = 6736 count = 75 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 316.441742 last_received_ts = 316.441772 last_seq = 6736 current_ts = 316.458405 current_received_ts = 316.457947 current_seq = 6737 count = 76 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 46us (kms_flip:2394) DEBUG: name = flip last_ts = 316.458405 last_received_ts = 316.457947 last_seq = 6737 current_ts = 316.475067 current_received_ts = 316.474884 current_seq = 6738 count = 77 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.475067 last_received_ts = 316.474884 last_seq = 6738 current_ts = 316.491730 current_received_ts = 316.491608 current_seq = 6739 count = 78 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.491730 last_received_ts = 316.491608 last_seq = 6739 current_ts = 316.508392 current_received_ts = 316.508240 current_seq = 6740 count = 79 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.508392 last_received_ts = 316.508240 last_seq = 6740 current_ts = 316.525055 current_received_ts = 316.524872 current_seq = 6741 count = 80 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.525055 last_received_ts = 316.524872 last_seq = 6741 current_ts = 316.541748 current_received_ts = 316.541748 current_seq = 6742 count = 81 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 316.541748 last_received_ts = 316.541748 last_seq = 6742 current_ts = 316.558411 current_received_ts = 316.557922 current_seq = 6743 count = 82 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 316.558411 last_received_ts = 316.557922 last_seq = 6743 current_ts = 316.575073 current_received_ts = 316.574646 current_seq = 6744 count = 83 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.575073 last_received_ts = 316.574646 last_seq = 6744 current_ts = 316.591736 current_received_ts = 316.591492 current_seq = 6745 count = 84 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.591736 last_received_ts = 316.591492 last_seq = 6745 current_ts = 316.608398 current_received_ts = 316.608276 current_seq = 6746 count = 85 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.608398 last_received_ts = 316.608276 last_seq = 6746 current_ts = 316.625061 current_received_ts = 316.624847 current_seq = 6747 count = 86 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.625061 last_received_ts = 316.624847 last_seq = 6747 current_ts = 316.641724 current_received_ts = 316.641571 current_seq = 6748 count = 87 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 316.641724 last_received_ts = 316.641571 last_seq = 6748 current_ts = 316.658417 current_received_ts = 316.658691 current_seq = 6749 count = 88 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.658417 last_received_ts = 316.658691 last_seq = 6749 current_ts = 316.675079 current_received_ts = 316.674652 current_seq = 6750 count = 89 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.675079 last_received_ts = 316.674652 last_seq = 6750 current_ts = 316.691742 current_received_ts = 316.691498 current_seq = 6751 count = 90 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.691742 last_received_ts = 316.691498 last_seq = 6751 current_ts = 316.708405 current_received_ts = 316.708282 current_seq = 6752 count = 91 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.708405 last_received_ts = 316.708282 last_seq = 6752 current_ts = 316.725067 current_received_ts = 316.724762 current_seq = 6753 count = 92 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.725067 last_received_ts = 316.724762 last_seq = 6753 current_ts = 316.741730 current_received_ts = 316.741516 current_seq = 6754 count = 93 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.741730 last_received_ts = 316.741516 last_seq = 6754 current_ts = 316.758392 current_received_ts = 316.758240 current_seq = 6755 count = 94 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.758392 last_received_ts = 316.758240 last_seq = 6755 current_ts = 316.775085 current_received_ts = 316.774689 current_seq = 6756 count = 95 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.775085 last_received_ts = 316.774689 last_seq = 6756 current_ts = 316.791748 current_received_ts = 316.791931 current_seq = 6757 count = 96 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 316.791748 last_received_ts = 316.791931 last_seq = 6757 current_ts = 316.808411 current_received_ts = 316.808228 current_seq = 6758 count = 97 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.808411 last_received_ts = 316.808228 last_seq = 6758 current_ts = 316.825073 current_received_ts = 316.824615 current_seq = 6759 count = 98 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 316.825073 last_received_ts = 316.824615 last_seq = 6759 current_ts = 316.841736 current_received_ts = 316.841400 current_seq = 6760 count = 99 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.841736 last_received_ts = 316.841400 last_seq = 6760 current_ts = 316.858398 current_received_ts = 316.858582 current_seq = 6761 count = 100 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 316.858398 last_received_ts = 316.858582 last_seq = 6761 current_ts = 316.875092 current_received_ts = 316.874695 current_seq = 6762 count = 101 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.875092 last_received_ts = 316.874695 last_seq = 6762 current_ts = 316.891754 current_received_ts = 316.891479 current_seq = 6763 count = 102 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.891754 last_received_ts = 316.891479 last_seq = 6763 current_ts = 316.908417 current_received_ts = 316.908051 current_seq = 6764 count = 103 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.908417 last_received_ts = 316.908051 last_seq = 6764 current_ts = 316.925079 current_received_ts = 316.924713 current_seq = 6765 count = 104 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 316.925079 last_received_ts = 316.924713 last_seq = 6765 current_ts = 316.941742 current_received_ts = 316.941498 current_seq = 6766 count = 105 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 316.941742 last_received_ts = 316.941498 last_seq = 6766 current_ts = 316.958405 current_received_ts = 316.958252 current_seq = 6767 count = 106 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 316.958405 last_received_ts = 316.958252 last_seq = 6767 current_ts = 316.975067 current_received_ts = 316.975067 current_seq = 6768 count = 107 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 45us (kms_flip:2394) DEBUG: name = flip last_ts = 316.975067 last_received_ts = 316.975067 last_seq = 6768 current_ts = 316.991760 current_received_ts = 316.991486 current_seq = 6769 count = 108 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 316.991760 last_received_ts = 316.991486 last_seq = 6769 current_ts = 317.008423 current_received_ts = 317.008301 current_seq = 6770 count = 109 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 317.008423 last_received_ts = 317.008301 last_seq = 6770 current_ts = 317.025085 current_received_ts = 317.024628 current_seq = 6771 count = 110 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.025085 last_received_ts = 317.024628 last_seq = 6771 current_ts = 317.041748 current_received_ts = 317.041321 current_seq = 6772 count = 111 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.041748 last_received_ts = 317.041321 last_seq = 6772 current_ts = 317.058411 current_received_ts = 317.058258 current_seq = 6773 count = 112 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.058411 last_received_ts = 317.058258 last_seq = 6773 current_ts = 317.075073 current_received_ts = 317.074615 current_seq = 6774 count = 113 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.075073 last_received_ts = 317.074615 last_seq = 6774 current_ts = 317.091736 current_received_ts = 317.091553 current_seq = 6775 count = 114 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.091736 last_received_ts = 317.091553 last_seq = 6775 current_ts = 317.108429 current_received_ts = 317.107910 current_seq = 6776 count = 115 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.108429 last_received_ts = 317.107910 last_seq = 6776 current_ts = 317.125092 current_received_ts = 317.124664 current_seq = 6777 count = 116 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.125092 last_received_ts = 317.124664 last_seq = 6777 current_ts = 317.141754 current_received_ts = 317.141449 current_seq = 6778 count = 117 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.141754 last_received_ts = 317.141449 last_seq = 6778 current_ts = 317.158417 current_received_ts = 317.158264 current_seq = 6779 count = 118 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.158417 last_received_ts = 317.158264 last_seq = 6779 current_ts = 317.175079 current_received_ts = 317.174927 current_seq = 6780 count = 119 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.175079 last_received_ts = 317.174927 last_seq = 6780 current_ts = 317.191742 current_received_ts = 317.191254 current_seq = 6781 count = 120 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 317.191742 last_received_ts = 317.191254 last_seq = 6781 current_ts = 317.208435 current_received_ts = 317.208649 current_seq = 6782 count = 121 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 317.208435 last_received_ts = 317.208649 last_seq = 6782 current_ts = 317.225098 current_received_ts = 317.224670 current_seq = 6783 count = 122 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.225098 last_received_ts = 317.224670 last_seq = 6783 current_ts = 317.241760 current_received_ts = 317.241486 current_seq = 6784 count = 123 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.241760 last_received_ts = 317.241486 last_seq = 6784 current_ts = 317.258423 current_received_ts = 317.258301 current_seq = 6785 count = 124 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.258423 last_received_ts = 317.258301 last_seq = 6785 current_ts = 317.275085 current_received_ts = 317.274658 current_seq = 6786 count = 125 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.275085 last_received_ts = 317.274658 last_seq = 6786 current_ts = 317.291779 current_received_ts = 317.291443 current_seq = 6787 count = 126 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.291779 last_received_ts = 317.291443 last_seq = 6787 current_ts = 317.308441 current_received_ts = 317.307953 current_seq = 6788 count = 127 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.308441 last_received_ts = 317.307953 last_seq = 6788 current_ts = 317.325104 current_received_ts = 317.324738 current_seq = 6789 count = 128 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.325104 last_received_ts = 317.324738 last_seq = 6789 current_ts = 317.341766 current_received_ts = 317.341461 current_seq = 6790 count = 129 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.341766 last_received_ts = 317.341461 last_seq = 6790 current_ts = 317.358429 current_received_ts = 317.358276 current_seq = 6791 count = 130 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.358429 last_received_ts = 317.358276 last_seq = 6791 current_ts = 317.375092 current_received_ts = 317.374634 current_seq = 6792 count = 131 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.375092 last_received_ts = 317.374634 last_seq = 6792 current_ts = 317.391754 current_received_ts = 317.391815 current_seq = 6793 count = 132 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.391754 last_received_ts = 317.391815 last_seq = 6793 current_ts = 317.408417 current_received_ts = 317.407898 current_seq = 6794 count = 133 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.408417 last_received_ts = 317.407898 last_seq = 6794 current_ts = 317.425110 current_received_ts = 317.424713 current_seq = 6795 count = 134 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.425110 last_received_ts = 317.424713 last_seq = 6795 current_ts = 317.441772 current_received_ts = 317.441467 current_seq = 6796 count = 135 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.441772 last_received_ts = 317.441467 last_seq = 6796 current_ts = 317.458435 current_received_ts = 317.458252 current_seq = 6797 count = 136 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.458435 last_received_ts = 317.458252 last_seq = 6797 current_ts = 317.475098 current_received_ts = 317.474609 current_seq = 6798 count = 137 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 317.475098 last_received_ts = 317.474609 last_seq = 6798 current_ts = 317.491760 current_received_ts = 317.491272 current_seq = 6799 count = 138 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.491760 last_received_ts = 317.491272 last_seq = 6799 current_ts = 317.508423 current_received_ts = 317.508179 current_seq = 6800 count = 139 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.508423 last_received_ts = 317.508179 last_seq = 6800 current_ts = 317.525116 current_received_ts = 317.524689 current_seq = 6801 count = 140 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.525116 last_received_ts = 317.524689 last_seq = 6801 current_ts = 317.541779 current_received_ts = 317.541260 current_seq = 6802 count = 141 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 317.541779 last_received_ts = 317.541260 last_seq = 6802 current_ts = 317.558441 current_received_ts = 317.557953 current_seq = 6803 count = 142 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 75us (kms_flip:2394) DEBUG: name = flip last_ts = 317.558441 last_received_ts = 317.557953 last_seq = 6803 current_ts = 317.575104 current_received_ts = 317.574738 current_seq = 6804 count = 143 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.575104 last_received_ts = 317.574738 last_seq = 6804 current_ts = 317.591766 current_received_ts = 317.591522 current_seq = 6805 count = 144 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.591766 last_received_ts = 317.591522 last_seq = 6805 current_ts = 317.608429 current_received_ts = 317.608276 current_seq = 6806 count = 145 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.608429 last_received_ts = 317.608276 last_seq = 6806 current_ts = 317.625122 current_received_ts = 317.624725 current_seq = 6807 count = 146 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.625122 last_received_ts = 317.624725 last_seq = 6807 current_ts = 317.641785 current_received_ts = 317.641266 current_seq = 6808 count = 147 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.641785 last_received_ts = 317.641266 last_seq = 6808 current_ts = 317.658447 current_received_ts = 317.658722 current_seq = 6809 count = 148 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 317.658447 last_received_ts = 317.658722 last_seq = 6809 current_ts = 317.675110 current_received_ts = 317.674652 current_seq = 6810 count = 149 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 317.675110 last_received_ts = 317.674652 last_seq = 6810 current_ts = 317.691772 current_received_ts = 317.691467 current_seq = 6811 count = 150 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.691772 last_received_ts = 317.691467 last_seq = 6811 current_ts = 317.708435 current_received_ts = 317.708344 current_seq = 6812 count = 151 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 317.708435 last_received_ts = 317.708344 last_seq = 6812 current_ts = 317.725128 current_received_ts = 317.724731 current_seq = 6813 count = 152 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.725128 last_received_ts = 317.724731 last_seq = 6813 current_ts = 317.741791 current_received_ts = 317.741852 current_seq = 6814 count = 153 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.741791 last_received_ts = 317.741852 last_seq = 6814 current_ts = 317.758453 current_received_ts = 317.758331 current_seq = 6815 count = 154 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.758453 last_received_ts = 317.758331 last_seq = 6815 current_ts = 317.775116 current_received_ts = 317.774933 current_seq = 6816 count = 155 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 78us (kms_flip:2394) DEBUG: name = flip last_ts = 317.775116 last_received_ts = 317.774933 last_seq = 6816 current_ts = 317.791779 current_received_ts = 317.791718 current_seq = 6817 count = 156 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.791779 last_received_ts = 317.791718 last_seq = 6817 current_ts = 317.808441 current_received_ts = 317.808167 current_seq = 6818 count = 157 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 25us (kms_flip:2394) DEBUG: name = flip last_ts = 317.808441 last_received_ts = 317.808167 last_seq = 6818 current_ts = 317.825104 current_received_ts = 317.824707 current_seq = 6819 count = 158 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.825104 last_received_ts = 317.824707 last_seq = 6819 current_ts = 317.841766 current_received_ts = 317.841827 current_seq = 6820 count = 159 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.841766 last_received_ts = 317.841827 last_seq = 6820 current_ts = 317.858459 current_received_ts = 317.858246 current_seq = 6821 count = 160 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.858459 last_received_ts = 317.858246 last_seq = 6821 current_ts = 317.875092 current_received_ts = 317.874664 current_seq = 6822 count = 161 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 317.875092 last_received_ts = 317.874664 last_seq = 6822 current_ts = 317.891785 current_received_ts = 317.891846 current_seq = 6823 count = 162 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.891785 last_received_ts = 317.891846 last_seq = 6823 current_ts = 317.908447 current_received_ts = 317.907898 current_seq = 6824 count = 163 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.908447 last_received_ts = 317.907898 last_seq = 6824 current_ts = 317.925110 current_received_ts = 317.924622 current_seq = 6825 count = 164 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.925110 last_received_ts = 317.924622 last_seq = 6825 current_ts = 317.941772 current_received_ts = 317.941650 current_seq = 6826 count = 165 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.941772 last_received_ts = 317.941650 last_seq = 6826 current_ts = 317.958435 current_received_ts = 317.958282 current_seq = 6827 count = 166 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 317.958435 last_received_ts = 317.958282 last_seq = 6827 current_ts = 317.975128 current_received_ts = 317.974945 current_seq = 6828 count = 167 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 70us (kms_flip:2394) DEBUG: name = flip last_ts = 317.975128 last_received_ts = 317.974945 last_seq = 6828 current_ts = 317.991791 current_received_ts = 317.991547 current_seq = 6829 count = 168 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 317.991791 last_received_ts = 317.991547 last_seq = 6829 current_ts = 318.008453 current_received_ts = 318.008514 current_seq = 6830 count = 169 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 318.008453 last_received_ts = 318.008514 last_seq = 6830 current_ts = 318.025116 current_received_ts = 318.024780 current_seq = 6831 count = 170 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 318.025116 last_received_ts = 318.024780 last_seq = 6831 current_ts = 318.041779 current_received_ts = 318.041504 current_seq = 6832 count = 171 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 25us (kms_flip:2394) DEBUG: name = flip last_ts = 318.041779 last_received_ts = 318.041504 last_seq = 6832 current_ts = 318.058441 current_received_ts = 318.058258 current_seq = 6833 count = 172 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 21us (kms_flip:2394) DEBUG: name = flip last_ts = 318.058441 last_received_ts = 318.058258 last_seq = 6833 current_ts = 318.075134 current_received_ts = 318.074677 current_seq = 6834 count = 173 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 318.075134 last_received_ts = 318.074677 last_seq = 6834 current_ts = 318.091797 current_received_ts = 318.091583 current_seq = 6835 count = 174 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 318.091797 last_received_ts = 318.091583 last_seq = 6835 current_ts = 318.108459 current_received_ts = 318.107971 current_seq = 6836 count = 175 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 30us (kms_flip:2394) DEBUG: name = flip last_ts = 318.108459 last_received_ts = 318.107971 last_seq = 6836 current_ts = 318.125122 current_received_ts = 318.124847 current_seq = 6837 count = 176 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 318.125122 last_received_ts = 318.124847 last_seq = 6837 current_ts = 318.141785 current_received_ts = 318.141479 current_seq = 6838 count = 177 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 318.141785 last_received_ts = 318.141479 last_seq = 6838 current_ts = 318.158447 current_received_ts = 318.158356 current_seq = 6839 count = 178 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 46us (kms_flip:2394) DEBUG: name = flip last_ts = 318.158447 last_received_ts = 318.158356 last_seq = 6839 current_ts = 318.175110 current_received_ts = 318.174683 current_seq = 6840 count = 179 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 23us (kms_flip:2394) DEBUG: name = flip last_ts = 318.175110 last_received_ts = 318.174683 last_seq = 6840 current_ts = 318.191772 current_received_ts = 318.191772 current_seq = 6841 count = 180 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 318.191772 last_received_ts = 318.191772 last_seq = 6841 current_ts = 318.208466 current_received_ts = 318.207947 current_seq = 6842 count = 181 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 44us (kms_flip:2394) DEBUG: name = flip last_ts = 318.208466 last_received_ts = 318.207947 last_seq = 6842 current_ts = 318.225128 current_received_ts = 318.225067 current_seq = 6843 count = 182 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 20us (kms_flip:2394) DEBUG: name = flip last_ts = 318.225128 last_received_ts = 318.225067 last_seq = 6843 current_ts = 318.241791 current_received_ts = 318.241516 current_seq = 6844 count = 183 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 318.241791 last_received_ts = 318.241516 last_seq = 6844 current_ts = 318.258453 current_received_ts = 318.258301 current_seq = 6845 count = 184 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 318.258453 last_received_ts = 318.258301 last_seq = 6845 current_ts = 318.275116 current_received_ts = 318.274933 current_seq = 6846 count = 185 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 318.275116 last_received_ts = 318.274933 last_seq = 6846 current_ts = 318.291809 current_received_ts = 318.291748 current_seq = 6847 count = 186 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 22us (kms_flip:2394) DEBUG: name = flip last_ts = 318.291809 last_received_ts = 318.291748 last_seq = 6847 current_ts = 318.308472 current_received_ts = 318.308655 current_seq = 6848 count = 187 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 105us (kms_flip:2394) DEBUG: name = flip last_ts = 318.308472 last_received_ts = 318.308655 last_seq = 6848 current_ts = 318.325134 current_received_ts = 318.324768 current_seq = 6849 count = 188 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 24us (kms_flip:2394) DEBUG: name = flip last_ts = 318.325134 last_received_ts = 318.324768 last_seq = 6849 current_ts = 318.341797 current_received_ts = 318.341461 current_seq = 6850 count = 189 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 13us (kms_flip:2394) DEBUG: name = flip last_ts = 318.341797 last_received_ts = 318.341461 last_seq = 6850 current_ts = 318.358459 current_received_ts = 318.357910 current_seq = 6851 count = 190 seq_step = 1 (kms_flip:2394) DEBUG: Vblank took 1134us (kms_flip:2394) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2394) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2394) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2394) igt_core-INFO: Stack trace: (kms_flip:2394) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2394) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:2394) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:2394) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() (kms_flip:2394) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:2394) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2394) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2394) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-HDMI-A2: FAIL (3.719s)
Dmesg	<6> [314.563719] [IGT] kms_flip: starting dynamic subtest B-HDMI-A2 <7> [314.565886] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:180] <7> [314.567456] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:182] <7> [314.606470] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:78:pipe A] <7> [314.606765] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [314.608889] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [314.609572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [314.609992] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [314.610499] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000) <7> [314.612504] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [314.613065] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [314.613450] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [314.615513] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [314.616044] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [314.616428] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [314.616808] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [314.618932] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [314.619389] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [314.619774] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [314.621566] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0) <7> [314.622951] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0) <7> [314.623414] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [314.623798] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [314.624235] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [314.625965] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [314.626374] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [314.626755] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [314.627506] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [314.629460] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [314.630248] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [314.630636] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [314.631765] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0) <7> [314.632388] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0) <7> [314.632775] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [314.633532] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [314.634178] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [314.634565] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [314.636477] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [314.637395] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in has_hdmi_sink (expected yes, found no) <7> [314.637791] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in has_infoframe (expected yes, found no) <7> [314.638786] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0) <7> [314.639580] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [314.640226] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [314.640611] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in port_clock (expected 222750, found 0) <7> [314.642517] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000) <7> [314.643321] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000) <7> [314.643709] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in avi infoframe <7> [314.645092] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [314.645498] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [314.645502] i915 0000:00:02.0: colorspace: RGB <7> [314.645506] i915 0000:00:02.0: scan mode: Underscan <7> [314.645510] i915 0000:00:02.0: colorimetry: No Data <7> [314.645513] i915 0000:00:02.0: picture aspect: No Data <7> [314.645516] i915 0000:00:02.0: active aspect: Same as Picture <7> [314.645520] i915 0000:00:02.0: itc: No Data <7> [314.645523] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [314.645526] i915 0000:00:02.0: quantization range: Full <7> [314.645529] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [314.645532] i915 0000:00:02.0: video code: 0 <7> [314.645535] i915 0000:00:02.0: ycc quantization range: Full <7> [314.645539] i915 0000:00:02.0: hdmi content type: Graphics <7> [314.645542] i915 0000:00:02.0: pixel repeat: 0 <7> [314.645545] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [314.645549] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [314.646606] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in spd infoframe <7> [314.647275] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [314.647658] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [314.647663] i915 0000:00:02.0: vendor: Intel <7> [314.647667] i915 0000:00:02.0: product: Integrated gfx <7> [314.647670] i915 0000:00:02.0: source device information: PC General (0x9) <7> [314.647674] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [314.649639] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hdmi infoframe <7> [314.650431] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [314.650824] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [314.650828] i915 0000:00:02.0: empty frame <7> [314.650832] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [314.653005] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:78:pipe A] fastset requirement not met, forcing full modeset <7> [314.653419] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:78:pipe A] releasing PORT PLL C <7> [314.654073] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:78:pipe A] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [314.654511] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:72:cursor A] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0 <7> [314.655157] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:78:pipe A] min cdclk: 192000 kHz -> 0 kHz <7> [314.655600] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [314.656661] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz <7> [314.657342] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4 <7> [314.657737] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:78:pipe A] enable: no [modeset] <7> [314.659647] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:36:plane 1A] fb: [NOFB], visible: no <7> [314.660992] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:45:plane 2A] fb: [NOFB], visible: no <7> [314.661387] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:plane 3A] fb: [NOFB], visible: no <7> [314.661766] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 4A] fb: [NOFB], visible: no <7> [314.662523] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:72:cursor A] fb: [NOFB], visible: no <7> [314.663488] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:176:HDMI-A-2][ENCODER:175:DDI C/PHY C] Disable audio codec on [CRTC:78:pipe A] <7> [314.685300] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port C <7> [314.688038] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A <7> [314.698487] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10 <7> [314.702985] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time <7> [314.811455] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_C <7> [314.812363] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL C (active 0x1, on? 1) for [CRTC:78:pipe A] <7> [314.815288] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL C <7> [314.815814] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 79200 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 4 <7> [314.816518] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B] <7> [314.817812] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:175:DDI C/PHY C] <7> [314.818662] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:176:HDMI-A-2] <7> [314.819585] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-c <7> [314.820235] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:78:pipe A] <7> [314.823056] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B] <7> [314.822943] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [314.823432] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz <7> [314.823815] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13 <7> [314.824443] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B] <7> [314.824673] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 316800 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 13 <7> [314.825869] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:164:pipe C] <7> [314.826166] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B] <7> [314.826222] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:176:HDMI-A-2] <7> [314.826418] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [314.826939] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:121:pipe B] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [314.827643] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:175:DDI C/PHY C] [CRTC:121:pipe B] <7> [314.828117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.enable (expected no, found yes) <7> [314.828506] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.active (expected no, found yes) <7> [314.828888] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1) <7> [314.829607] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in lane_count (expected 0, found 4) <7> [314.830308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d) <7> [314.830694] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [314.831131] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL <7> [314.831148] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled <7> [314.831250] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [314.831641] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [314.832128] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [314.832525] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [314.833099] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [314.833537] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [314.834055] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [314.834463] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [314.834854] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [314.835442] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [314.835827] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [314.836349] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [314.836757] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [314.837309] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [314.837714] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [314.838231] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [314.838636] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [314.839172] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [314.839556] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [314.840025] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [314.840425] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [314.841262] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [314.841718] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [314.842248] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [314.842659] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [314.843167] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [314.843588] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [314.844094] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [314.844478] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [314.844864] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in has_infoframe (expected no, found yes) <7> [314.845490] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [314.846090] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [314.846487] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [314.846868] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in port_clock (expected 0, found 222750) <7> [314.847382] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [314.847769] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [314.848259] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in avi infoframe <7> [314.848720] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [314.849250] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [314.849661] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [314.849666] i915 0000:00:02.0: colorspace: RGB <7> [314.849670] i915 0000:00:02.0: scan mode: Underscan <7> [314.849673] i915 0000:00:02.0: colorimetry: No Data <7> [314.849676] i915 0000:00:02.0: picture aspect: No Data <7> [314.849679] i915 0000:00:02.0: active aspect: Same as Picture <7> [314.849682] i915 0000:00:02.0: itc: No Data <7> [314.849685] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [314.849689] i915 0000:00:02.0: quantization range: Full <7> [314.849692] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [314.849695] i915 0000:00:02.0: video code: 0 <7> [314.849698] i915 0000:00:02.0: ycc quantization range: Full <7> [314.849701] i915 0000:00:02.0: hdmi content type: Graphics <7> [314.849705] i915 0000:00:02.0: pixel repeat: 0 <7> [314.849708] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [314.849711] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in spd infoframe <7> [314.850281] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [314.850685] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [314.851162] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [314.851167] i915 0000:00:02.0: vendor: Intel <7> [314.851199] i915 0000:00:02.0: product: Integrated gfx <7> [314.851203] i915 0000:00:02.0: source device information: PC General (0x9) <7> [314.851207] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hdmi infoframe <7> [314.851587] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [314.852113] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [314.852555] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [314.852560] i915 0000:00:02.0: empty frame <7> [314.852566] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:121:pipe B] fastset requirement not met, forcing full modeset <7> [314.853225] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:121:pipe B] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x2 <7> [314.853680] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:79:plane 1B] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988 <7> [314.854150] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:115:cursor B] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32 <7> [314.854529] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [314.855001] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0 <7> [314.855391] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0 <7> [314.855763] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0 <7> [314.856250] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] min_ddb_uv 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [314.856676] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:121:pipe B] min cdclk: 0 kHz -> 192000 kHz <7> [314.857205] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:121:pipe B] using pre-allocated PORT PLL C <7> [314.857690] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:121:pipe B] reserving PORT PLL C <7> [314.858356] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:121:pipe B] enable: yes [modeset] <7> [314.858806] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [314.859357] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 36, dithering: 0 <7> [314.859767] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [314.860270] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [314.860661] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [314.861179] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [314.861579] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [314.862127] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [314.862514] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [314.862518] i915 0000:00:02.0: colorspace: RGB <7> [314.862522] i915 0000:00:02.0: scan mode: Underscan <7> [314.862525] i915 0000:00:02.0: colorimetry: No Data <7> [314.862529] i915 0000:00:02.0: picture aspect: No Data <7> [314.862532] i915 0000:00:02.0: active aspect: Same as Picture <7> [314.862535] i915 0000:00:02.0: itc: No Data <7> [314.862538] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [314.862541] i915 0000:00:02.0: quantization range: Full <7> [314.862548] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [314.862551] i915 0000:00:02.0: video code: 0 <7> [314.862554] i915 0000:00:02.0: ycc quantization range: Full <7> [314.862557] i915 0000:00:02.0: hdmi content type: Graphics <7> [314.862561] i915 0000:00:02.0: pixel repeat: 0 <7> [314.862564] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [314.862568] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [314.862572] i915 0000:00:02.0: vendor: Intel <7> [314.862575] i915 0000:00:02.0: product: Integrated gfx <7> [314.862579] i915 0000:00:02.0: source device information: PC General (0x9) <7> [314.862583] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [314.862586] i915 0000:00:02.0: empty frame <7> [314.862590] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00 <7> [314.863128] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00 <7> [314.863525] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [314.864023] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [314.864405] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0 <7> [314.864785] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0 <7> [314.865264] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [314.865648] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 <7> [314.866360] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 <7> [314.866748] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [314.867216] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [314.867596] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [314.868144] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pixel rate 148500, min cdclk 192000, min voltage level 0 <7> [314.868556] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0 <7> [314.869067] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [314.869473] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [314.869855] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [314.870368] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [314.870782] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [314.871296] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6200, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d <7> [314.871680] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [314.872215] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [314.872617] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [314.873113] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [314.873508] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [314.873883] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [314.874404] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [314.874792] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:79:plane 1B] fb: [FB:180] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [314.875292] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [314.875670] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [314.876140] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:88:plane 2B] fb: [NOFB], visible: no <7> [314.876615] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:97:plane 3B] fb: [NOFB], visible: no <7> [314.877255] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:106:plane 4B] fb: [NOFB], visible: no <7> [314.877709] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:115:cursor B] fb: [NOFB], visible: no <7> [314.879004] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c <7> [314.879814] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B] <7> [314.880310] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:175:DDI C/PHY C] <7> [314.880877] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x2, on? 0) for [CRTC:121:pipe B] <7> [314.881545] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C <7> [314.882209] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C <7> [314.882702] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe B <7> [314.916977] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:176:HDMI-A-2][ENCODER:175:DDI C/PHY C] Enable audio codec on [CRTC:121:pipe B], 32 bytes ELD <7> [314.933706] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000) <7> [314.934202] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N <7> [314.934759] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:176:HDMI-A-2] <7> [314.936662] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:121:pipe B] <6> [318.287791] [IGT] kms_flip: finished subtest B-HDMI-A2, FAIL

Detail

Value

Duration

3.72 seconds

Hostname

shard-glk2

Igt-Version

IGT-Version: 2.4-ge3bf68535 (x86_64) (Linux: 7.1.0-rc2-CI_DRM_18409-g9160312bed53+ x86_64)

Out

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

Err

Starting dynamic subtest: B-HDMI-A2
(kms_flip:2394) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2394) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2394) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.341736
last_received_ts = 316.341431
last_seq = 6730
current_ts = 316.358398
current_received_ts = 316.358337
current_seq = 6731
count = 70
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.358398
last_received_ts = 316.358337
last_seq = 6731
current_ts = 316.375061
current_received_ts = 316.374634
current_seq = 6732
count = 71
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.375061
last_received_ts = 316.374634
last_seq = 6732
current_ts = 316.391724
current_received_ts = 316.391479
current_seq = 6733
count = 72
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.391724
last_received_ts = 316.391479
last_seq = 6733
current_ts = 316.408417
current_received_ts = 316.408142
current_seq = 6734
count = 73
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.408417
last_received_ts = 316.408142
last_seq = 6734
current_ts = 316.425079
current_received_ts = 316.424622
current_seq = 6735
count = 74
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.425079
last_received_ts = 316.424622
last_seq = 6735
current_ts = 316.441742
current_received_ts = 316.441772
current_seq = 6736
count = 75
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.441742
last_received_ts = 316.441772
last_seq = 6736
current_ts = 316.458405
current_received_ts = 316.457947
current_seq = 6737
count = 76
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 46us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.458405
last_received_ts = 316.457947
last_seq = 6737
current_ts = 316.475067
current_received_ts = 316.474884
current_seq = 6738
count = 77
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.475067
last_received_ts = 316.474884
last_seq = 6738
current_ts = 316.491730
current_received_ts = 316.491608
current_seq = 6739
count = 78
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.491730
last_received_ts = 316.491608
last_seq = 6739
current_ts = 316.508392
current_received_ts = 316.508240
current_seq = 6740
count = 79
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.508392
last_received_ts = 316.508240
last_seq = 6740
current_ts = 316.525055
current_received_ts = 316.524872
current_seq = 6741
count = 80
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.525055
last_received_ts = 316.524872
last_seq = 6741
current_ts = 316.541748
current_received_ts = 316.541748
current_seq = 6742
count = 81
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.541748
last_received_ts = 316.541748
last_seq = 6742
current_ts = 316.558411
current_received_ts = 316.557922
current_seq = 6743
count = 82
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.558411
last_received_ts = 316.557922
last_seq = 6743
current_ts = 316.575073
current_received_ts = 316.574646
current_seq = 6744
count = 83
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.575073
last_received_ts = 316.574646
last_seq = 6744
current_ts = 316.591736
current_received_ts = 316.591492
current_seq = 6745
count = 84
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.591736
last_received_ts = 316.591492
last_seq = 6745
current_ts = 316.608398
current_received_ts = 316.608276
current_seq = 6746
count = 85
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.608398
last_received_ts = 316.608276
last_seq = 6746
current_ts = 316.625061
current_received_ts = 316.624847
current_seq = 6747
count = 86
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.625061
last_received_ts = 316.624847
last_seq = 6747
current_ts = 316.641724
current_received_ts = 316.641571
current_seq = 6748
count = 87
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.641724
last_received_ts = 316.641571
last_seq = 6748
current_ts = 316.658417
current_received_ts = 316.658691
current_seq = 6749
count = 88
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.658417
last_received_ts = 316.658691
last_seq = 6749
current_ts = 316.675079
current_received_ts = 316.674652
current_seq = 6750
count = 89
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.675079
last_received_ts = 316.674652
last_seq = 6750
current_ts = 316.691742
current_received_ts = 316.691498
current_seq = 6751
count = 90
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.691742
last_received_ts = 316.691498
last_seq = 6751
current_ts = 316.708405
current_received_ts = 316.708282
current_seq = 6752
count = 91
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.708405
last_received_ts = 316.708282
last_seq = 6752
current_ts = 316.725067
current_received_ts = 316.724762
current_seq = 6753
count = 92
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.725067
last_received_ts = 316.724762
last_seq = 6753
current_ts = 316.741730
current_received_ts = 316.741516
current_seq = 6754
count = 93
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.741730
last_received_ts = 316.741516
last_seq = 6754
current_ts = 316.758392
current_received_ts = 316.758240
current_seq = 6755
count = 94
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.758392
last_received_ts = 316.758240
last_seq = 6755
current_ts = 316.775085
current_received_ts = 316.774689
current_seq = 6756
count = 95
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.775085
last_received_ts = 316.774689
last_seq = 6756
current_ts = 316.791748
current_received_ts = 316.791931
current_seq = 6757
count = 96
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.791748
last_received_ts = 316.791931
last_seq = 6757
current_ts = 316.808411
current_received_ts = 316.808228
current_seq = 6758
count = 97
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.808411
last_received_ts = 316.808228
last_seq = 6758
current_ts = 316.825073
current_received_ts = 316.824615
current_seq = 6759
count = 98
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.825073
last_received_ts = 316.824615
last_seq = 6759
current_ts = 316.841736
current_received_ts = 316.841400
current_seq = 6760
count = 99
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.841736
last_received_ts = 316.841400
last_seq = 6760
current_ts = 316.858398
current_received_ts = 316.858582
current_seq = 6761
count = 100
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.858398
last_received_ts = 316.858582
last_seq = 6761
current_ts = 316.875092
current_received_ts = 316.874695
current_seq = 6762
count = 101
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.875092
last_received_ts = 316.874695
last_seq = 6762
current_ts = 316.891754
current_received_ts = 316.891479
current_seq = 6763
count = 102
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.891754
last_received_ts = 316.891479
last_seq = 6763
current_ts = 316.908417
current_received_ts = 316.908051
current_seq = 6764
count = 103
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.908417
last_received_ts = 316.908051
last_seq = 6764
current_ts = 316.925079
current_received_ts = 316.924713
current_seq = 6765
count = 104
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.925079
last_received_ts = 316.924713
last_seq = 6765
current_ts = 316.941742
current_received_ts = 316.941498
current_seq = 6766
count = 105
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.941742
last_received_ts = 316.941498
last_seq = 6766
current_ts = 316.958405
current_received_ts = 316.958252
current_seq = 6767
count = 106
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.958405
last_received_ts = 316.958252
last_seq = 6767
current_ts = 316.975067
current_received_ts = 316.975067
current_seq = 6768
count = 107
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 45us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.975067
last_received_ts = 316.975067
last_seq = 6768
current_ts = 316.991760
current_received_ts = 316.991486
current_seq = 6769
count = 108
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 316.991760
last_received_ts = 316.991486
last_seq = 6769
current_ts = 317.008423
current_received_ts = 317.008301
current_seq = 6770
count = 109
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.008423
last_received_ts = 317.008301
last_seq = 6770
current_ts = 317.025085
current_received_ts = 317.024628
current_seq = 6771
count = 110
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.025085
last_received_ts = 317.024628
last_seq = 6771
current_ts = 317.041748
current_received_ts = 317.041321
current_seq = 6772
count = 111
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.041748
last_received_ts = 317.041321
last_seq = 6772
current_ts = 317.058411
current_received_ts = 317.058258
current_seq = 6773
count = 112
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.058411
last_received_ts = 317.058258
last_seq = 6773
current_ts = 317.075073
current_received_ts = 317.074615
current_seq = 6774
count = 113
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.075073
last_received_ts = 317.074615
last_seq = 6774
current_ts = 317.091736
current_received_ts = 317.091553
current_seq = 6775
count = 114
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.091736
last_received_ts = 317.091553
last_seq = 6775
current_ts = 317.108429
current_received_ts = 317.107910
current_seq = 6776
count = 115
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.108429
last_received_ts = 317.107910
last_seq = 6776
current_ts = 317.125092
current_received_ts = 317.124664
current_seq = 6777
count = 116
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.125092
last_received_ts = 317.124664
last_seq = 6777
current_ts = 317.141754
current_received_ts = 317.141449
current_seq = 6778
count = 117
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.141754
last_received_ts = 317.141449
last_seq = 6778
current_ts = 317.158417
current_received_ts = 317.158264
current_seq = 6779
count = 118
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.158417
last_received_ts = 317.158264
last_seq = 6779
current_ts = 317.175079
current_received_ts = 317.174927
current_seq = 6780
count = 119
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.175079
last_received_ts = 317.174927
last_seq = 6780
current_ts = 317.191742
current_received_ts = 317.191254
current_seq = 6781
count = 120
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.191742
last_received_ts = 317.191254
last_seq = 6781
current_ts = 317.208435
current_received_ts = 317.208649
current_seq = 6782
count = 121
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.208435
last_received_ts = 317.208649
last_seq = 6782
current_ts = 317.225098
current_received_ts = 317.224670
current_seq = 6783
count = 122
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.225098
last_received_ts = 317.224670
last_seq = 6783
current_ts = 317.241760
current_received_ts = 317.241486
current_seq = 6784
count = 123
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.241760
last_received_ts = 317.241486
last_seq = 6784
current_ts = 317.258423
current_received_ts = 317.258301
current_seq = 6785
count = 124
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.258423
last_received_ts = 317.258301
last_seq = 6785
current_ts = 317.275085
current_received_ts = 317.274658
current_seq = 6786
count = 125
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.275085
last_received_ts = 317.274658
last_seq = 6786
current_ts = 317.291779
current_received_ts = 317.291443
current_seq = 6787
count = 126
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.291779
last_received_ts = 317.291443
last_seq = 6787
current_ts = 317.308441
current_received_ts = 317.307953
current_seq = 6788
count = 127
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.308441
last_received_ts = 317.307953
last_seq = 6788
current_ts = 317.325104
current_received_ts = 317.324738
current_seq = 6789
count = 128
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.325104
last_received_ts = 317.324738
last_seq = 6789
current_ts = 317.341766
current_received_ts = 317.341461
current_seq = 6790
count = 129
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.341766
last_received_ts = 317.341461
last_seq = 6790
current_ts = 317.358429
current_received_ts = 317.358276
current_seq = 6791
count = 130
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.358429
last_received_ts = 317.358276
last_seq = 6791
current_ts = 317.375092
current_received_ts = 317.374634
current_seq = 6792
count = 131
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.375092
last_received_ts = 317.374634
last_seq = 6792
current_ts = 317.391754
current_received_ts = 317.391815
current_seq = 6793
count = 132
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.391754
last_received_ts = 317.391815
last_seq = 6793
current_ts = 317.408417
current_received_ts = 317.407898
current_seq = 6794
count = 133
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.408417
last_received_ts = 317.407898
last_seq = 6794
current_ts = 317.425110
current_received_ts = 317.424713
current_seq = 6795
count = 134
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.425110
last_received_ts = 317.424713
last_seq = 6795
current_ts = 317.441772
current_received_ts = 317.441467
current_seq = 6796
count = 135
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.441772
last_received_ts = 317.441467
last_seq = 6796
current_ts = 317.458435
current_received_ts = 317.458252
current_seq = 6797
count = 136
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.458435
last_received_ts = 317.458252
last_seq = 6797
current_ts = 317.475098
current_received_ts = 317.474609
current_seq = 6798
count = 137
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.475098
last_received_ts = 317.474609
last_seq = 6798
current_ts = 317.491760
current_received_ts = 317.491272
current_seq = 6799
count = 138
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.491760
last_received_ts = 317.491272
last_seq = 6799
current_ts = 317.508423
current_received_ts = 317.508179
current_seq = 6800
count = 139
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.508423
last_received_ts = 317.508179
last_seq = 6800
current_ts = 317.525116
current_received_ts = 317.524689
current_seq = 6801
count = 140
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.525116
last_received_ts = 317.524689
last_seq = 6801
current_ts = 317.541779
current_received_ts = 317.541260
current_seq = 6802
count = 141
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.541779
last_received_ts = 317.541260
last_seq = 6802
current_ts = 317.558441
current_received_ts = 317.557953
current_seq = 6803
count = 142
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 75us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.558441
last_received_ts = 317.557953
last_seq = 6803
current_ts = 317.575104
current_received_ts = 317.574738
current_seq = 6804
count = 143
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.575104
last_received_ts = 317.574738
last_seq = 6804
current_ts = 317.591766
current_received_ts = 317.591522
current_seq = 6805
count = 144
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.591766
last_received_ts = 317.591522
last_seq = 6805
current_ts = 317.608429
current_received_ts = 317.608276
current_seq = 6806
count = 145
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.608429
last_received_ts = 317.608276
last_seq = 6806
current_ts = 317.625122
current_received_ts = 317.624725
current_seq = 6807
count = 146
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.625122
last_received_ts = 317.624725
last_seq = 6807
current_ts = 317.641785
current_received_ts = 317.641266
current_seq = 6808
count = 147
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.641785
last_received_ts = 317.641266
last_seq = 6808
current_ts = 317.658447
current_received_ts = 317.658722
current_seq = 6809
count = 148
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.658447
last_received_ts = 317.658722
last_seq = 6809
current_ts = 317.675110
current_received_ts = 317.674652
current_seq = 6810
count = 149
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.675110
last_received_ts = 317.674652
last_seq = 6810
current_ts = 317.691772
current_received_ts = 317.691467
current_seq = 6811
count = 150
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.691772
last_received_ts = 317.691467
last_seq = 6811
current_ts = 317.708435
current_received_ts = 317.708344
current_seq = 6812
count = 151
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.708435
last_received_ts = 317.708344
last_seq = 6812
current_ts = 317.725128
current_received_ts = 317.724731
current_seq = 6813
count = 152
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.725128
last_received_ts = 317.724731
last_seq = 6813
current_ts = 317.741791
current_received_ts = 317.741852
current_seq = 6814
count = 153
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.741791
last_received_ts = 317.741852
last_seq = 6814
current_ts = 317.758453
current_received_ts = 317.758331
current_seq = 6815
count = 154
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.758453
last_received_ts = 317.758331
last_seq = 6815
current_ts = 317.775116
current_received_ts = 317.774933
current_seq = 6816
count = 155
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 78us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.775116
last_received_ts = 317.774933
last_seq = 6816
current_ts = 317.791779
current_received_ts = 317.791718
current_seq = 6817
count = 156
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.791779
last_received_ts = 317.791718
last_seq = 6817
current_ts = 317.808441
current_received_ts = 317.808167
current_seq = 6818
count = 157
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 25us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.808441
last_received_ts = 317.808167
last_seq = 6818
current_ts = 317.825104
current_received_ts = 317.824707
current_seq = 6819
count = 158
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.825104
last_received_ts = 317.824707
last_seq = 6819
current_ts = 317.841766
current_received_ts = 317.841827
current_seq = 6820
count = 159
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.841766
last_received_ts = 317.841827
last_seq = 6820
current_ts = 317.858459
current_received_ts = 317.858246
current_seq = 6821
count = 160
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.858459
last_received_ts = 317.858246
last_seq = 6821
current_ts = 317.875092
current_received_ts = 317.874664
current_seq = 6822
count = 161
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.875092
last_received_ts = 317.874664
last_seq = 6822
current_ts = 317.891785
current_received_ts = 317.891846
current_seq = 6823
count = 162
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.891785
last_received_ts = 317.891846
last_seq = 6823
current_ts = 317.908447
current_received_ts = 317.907898
current_seq = 6824
count = 163
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.908447
last_received_ts = 317.907898
last_seq = 6824
current_ts = 317.925110
current_received_ts = 317.924622
current_seq = 6825
count = 164
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.925110
last_received_ts = 317.924622
last_seq = 6825
current_ts = 317.941772
current_received_ts = 317.941650
current_seq = 6826
count = 165
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.941772
last_received_ts = 317.941650
last_seq = 6826
current_ts = 317.958435
current_received_ts = 317.958282
current_seq = 6827
count = 166
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.958435
last_received_ts = 317.958282
last_seq = 6827
current_ts = 317.975128
current_received_ts = 317.974945
current_seq = 6828
count = 167
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 70us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.975128
last_received_ts = 317.974945
last_seq = 6828
current_ts = 317.991791
current_received_ts = 317.991547
current_seq = 6829
count = 168
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 317.991791
last_received_ts = 317.991547
last_seq = 6829
current_ts = 318.008453
current_received_ts = 318.008514
current_seq = 6830
count = 169
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.008453
last_received_ts = 318.008514
last_seq = 6830
current_ts = 318.025116
current_received_ts = 318.024780
current_seq = 6831
count = 170
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.025116
last_received_ts = 318.024780
last_seq = 6831
current_ts = 318.041779
current_received_ts = 318.041504
current_seq = 6832
count = 171
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 25us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.041779
last_received_ts = 318.041504
last_seq = 6832
current_ts = 318.058441
current_received_ts = 318.058258
current_seq = 6833
count = 172
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 21us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.058441
last_received_ts = 318.058258
last_seq = 6833
current_ts = 318.075134
current_received_ts = 318.074677
current_seq = 6834
count = 173
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.075134
last_received_ts = 318.074677
last_seq = 6834
current_ts = 318.091797
current_received_ts = 318.091583
current_seq = 6835
count = 174
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.091797
last_received_ts = 318.091583
last_seq = 6835
current_ts = 318.108459
current_received_ts = 318.107971
current_seq = 6836
count = 175
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 30us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.108459
last_received_ts = 318.107971
last_seq = 6836
current_ts = 318.125122
current_received_ts = 318.124847
current_seq = 6837
count = 176
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.125122
last_received_ts = 318.124847
last_seq = 6837
current_ts = 318.141785
current_received_ts = 318.141479
current_seq = 6838
count = 177
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.141785
last_received_ts = 318.141479
last_seq = 6838
current_ts = 318.158447
current_received_ts = 318.158356
current_seq = 6839
count = 178
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 46us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.158447
last_received_ts = 318.158356
last_seq = 6839
current_ts = 318.175110
current_received_ts = 318.174683
current_seq = 6840
count = 179
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 23us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.175110
last_received_ts = 318.174683
last_seq = 6840
current_ts = 318.191772
current_received_ts = 318.191772
current_seq = 6841
count = 180
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.191772
last_received_ts = 318.191772
last_seq = 6841
current_ts = 318.208466
current_received_ts = 318.207947
current_seq = 6842
count = 181
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 44us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.208466
last_received_ts = 318.207947
last_seq = 6842
current_ts = 318.225128
current_received_ts = 318.225067
current_seq = 6843
count = 182
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 20us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.225128
last_received_ts = 318.225067
last_seq = 6843
current_ts = 318.241791
current_received_ts = 318.241516
current_seq = 6844
count = 183
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.241791
last_received_ts = 318.241516
last_seq = 6844
current_ts = 318.258453
current_received_ts = 318.258301
current_seq = 6845
count = 184
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.258453
last_received_ts = 318.258301
last_seq = 6845
current_ts = 318.275116
current_received_ts = 318.274933
current_seq = 6846
count = 185
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.275116
last_received_ts = 318.274933
last_seq = 6846
current_ts = 318.291809
current_received_ts = 318.291748
current_seq = 6847
count = 186
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 22us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.291809
last_received_ts = 318.291748
last_seq = 6847
current_ts = 318.308472
current_received_ts = 318.308655
current_seq = 6848
count = 187
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 105us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.308472
last_received_ts = 318.308655
last_seq = 6848
current_ts = 318.325134
current_received_ts = 318.324768
current_seq = 6849
count = 188
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 24us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.325134
last_received_ts = 318.324768
last_seq = 6849
current_ts = 318.341797
current_received_ts = 318.341461
current_seq = 6850
count = 189
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 13us
(kms_flip:2394) DEBUG: name = flip
last_ts = 318.341797
last_received_ts = 318.341461
last_seq = 6850
current_ts = 318.358459
current_received_ts = 318.357910
current_seq = 6851
count = 190
seq_step = 1
(kms_flip:2394) DEBUG: Vblank took 1134us
(kms_flip:2394) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2394) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2394) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2394) igt_core-INFO: Stack trace:
(kms_flip:2394) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2394) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2394) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2394) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2394) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2394) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2394) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2394) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-HDMI-A2: FAIL (3.719s)

Dmesg

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

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

<7> [314.567456] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:182]

<7> [314.606470] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:78:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [314.663488] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:176:HDMI-A-2][ENCODER:175:DDI C/PHY C] Disable audio codec on [CRTC:78:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

<7> [314.820235] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:78:pipe A]

<7> [314.823056] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B]

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

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

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

<7> [314.824443] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B]

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

<7> [314.825869] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:164:pipe C]

<7> [314.826166] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B]

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

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

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

<7> [314.827643] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:175:DDI C/PHY C] [CRTC:121:pipe B]

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

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

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

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

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

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

<7> [314.831131] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL

<7> [314.831148] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [314.853680] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:79:plane 1B] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988

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

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

<7> [314.855001] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0

<7> [314.855391] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0

<7> [314.855763] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0

<7> [314.856250] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:79:plane 1B] min_ddb_uv 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [314.862590] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00

<7> [314.863128] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00

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

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

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

<7> [314.864785] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0

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

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

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

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

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

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

<7> [314.868144] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pixel rate 148500, min cdclk 192000, min voltage level 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [314.936662] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:121:pipe B]

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

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