igt@kms_flip@flip-vs-expired-vblank@a-hdmi-a1 on shard-snb@CI_DRM

Detail	Value
Duration	3.86 seconds
Hostname	shard-snb6
Igt-Version	IGT-Version: 2.4-g1295cc9cf (x86_64) (Linux: 7.0.0-rc6-CI_DRM_18267-gf1d4727d10d2+ x86_64)
Out	Starting dynamic subtest: A-HDMI-A1 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:925 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1891 run_test() #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047() #4 ../tests/kms_flip.c:2047 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A1: FAIL (3.863s)
Err	Starting dynamic subtest: A-HDMI-A1 (kms_flip:18417) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:930: (kms_flip:18417) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-HDMI-A1 failed. ** DEBUG (kms_flip:18417) DEBUG: name = flip last_ts = 245.917206 last_received_ts = 245.916733 last_seq = 8848 current_ts = 245.933838 current_received_ts = 245.933365 current_seq = 8849 count = 75 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 245.933838 last_received_ts = 245.933365 last_seq = 8849 current_ts = 245.950470 current_received_ts = 245.949997 current_seq = 8850 count = 76 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 245.950470 last_received_ts = 245.949997 last_seq = 8850 current_ts = 245.967102 current_received_ts = 245.966629 current_seq = 8851 count = 77 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 245.967102 last_received_ts = 245.966629 last_seq = 8851 current_ts = 245.983734 current_received_ts = 245.983261 current_seq = 8852 count = 78 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 245.983734 last_received_ts = 245.983261 last_seq = 8852 current_ts = 246.000366 current_received_ts = 245.999908 current_seq = 8853 count = 79 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.000366 last_received_ts = 245.999908 last_seq = 8853 current_ts = 246.017014 current_received_ts = 246.016510 current_seq = 8854 count = 80 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.017014 last_received_ts = 246.016510 last_seq = 8854 current_ts = 246.033646 current_received_ts = 246.033142 current_seq = 8855 count = 81 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.033646 last_received_ts = 246.033142 last_seq = 8855 current_ts = 246.050262 current_received_ts = 246.049805 current_seq = 8856 count = 82 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.050262 last_received_ts = 246.049805 last_seq = 8856 current_ts = 246.066910 current_received_ts = 246.066437 current_seq = 8857 count = 83 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.066910 last_received_ts = 246.066437 last_seq = 8857 current_ts = 246.083542 current_received_ts = 246.083069 current_seq = 8858 count = 84 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.083542 last_received_ts = 246.083069 last_seq = 8858 current_ts = 246.100174 current_received_ts = 246.099701 current_seq = 8859 count = 85 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.100174 last_received_ts = 246.099701 last_seq = 8859 current_ts = 246.116806 current_received_ts = 246.116333 current_seq = 8860 count = 86 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.116806 last_received_ts = 246.116333 last_seq = 8860 current_ts = 246.133438 current_received_ts = 246.132965 current_seq = 8861 count = 87 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.133438 last_received_ts = 246.132965 last_seq = 8861 current_ts = 246.150070 current_received_ts = 246.149612 current_seq = 8862 count = 88 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.150070 last_received_ts = 246.149612 last_seq = 8862 current_ts = 246.166702 current_received_ts = 246.166229 current_seq = 8863 count = 89 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.166702 last_received_ts = 246.166229 last_seq = 8863 current_ts = 246.183334 current_received_ts = 246.182861 current_seq = 8864 count = 90 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.183334 last_received_ts = 246.182861 last_seq = 8864 current_ts = 246.199966 current_received_ts = 246.199493 current_seq = 8865 count = 91 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.199966 last_received_ts = 246.199493 last_seq = 8865 current_ts = 246.216599 current_received_ts = 246.216080 current_seq = 8866 count = 92 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.216599 last_received_ts = 246.216080 last_seq = 8866 current_ts = 246.233231 current_received_ts = 246.232742 current_seq = 8867 count = 93 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.233231 last_received_ts = 246.232742 last_seq = 8867 current_ts = 246.249863 current_received_ts = 246.249374 current_seq = 8868 count = 94 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.249863 last_received_ts = 246.249374 last_seq = 8868 current_ts = 246.266495 current_received_ts = 246.266037 current_seq = 8869 count = 95 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 9us (kms_flip:18417) DEBUG: name = flip last_ts = 246.266495 last_received_ts = 246.266037 last_seq = 8869 current_ts = 246.283127 current_received_ts = 246.282669 current_seq = 8870 count = 96 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.283127 last_received_ts = 246.282669 last_seq = 8870 current_ts = 246.299774 current_received_ts = 246.299301 current_seq = 8871 count = 97 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.299774 last_received_ts = 246.299301 last_seq = 8871 current_ts = 246.316406 current_received_ts = 246.315918 current_seq = 8872 count = 98 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.316406 last_received_ts = 246.315918 last_seq = 8872 current_ts = 246.333038 current_received_ts = 246.332596 current_seq = 8873 count = 99 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.333038 last_received_ts = 246.332596 last_seq = 8873 current_ts = 246.349670 current_received_ts = 246.349197 current_seq = 8874 count = 100 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.349670 last_received_ts = 246.349197 last_seq = 8874 current_ts = 246.366302 current_received_ts = 246.365875 current_seq = 8875 count = 101 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.366302 last_received_ts = 246.365875 last_seq = 8875 current_ts = 246.382935 current_received_ts = 246.382507 current_seq = 8876 count = 102 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.382935 last_received_ts = 246.382507 last_seq = 8876 current_ts = 246.399567 current_received_ts = 246.399124 current_seq = 8877 count = 103 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.399567 last_received_ts = 246.399124 last_seq = 8877 current_ts = 246.416199 current_received_ts = 246.415771 current_seq = 8878 count = 104 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.416199 last_received_ts = 246.415771 last_seq = 8878 current_ts = 246.432831 current_received_ts = 246.432373 current_seq = 8879 count = 105 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.432831 last_received_ts = 246.432373 last_seq = 8879 current_ts = 246.449463 current_received_ts = 246.449036 current_seq = 8880 count = 106 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.449463 last_received_ts = 246.449036 last_seq = 8880 current_ts = 246.466095 current_received_ts = 246.465668 current_seq = 8881 count = 107 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.466095 last_received_ts = 246.465668 last_seq = 8881 current_ts = 246.482727 current_received_ts = 246.482300 current_seq = 8882 count = 108 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.482727 last_received_ts = 246.482300 last_seq = 8882 current_ts = 246.499359 current_received_ts = 246.498932 current_seq = 8883 count = 109 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.499359 last_received_ts = 246.498932 last_seq = 8883 current_ts = 246.515991 current_received_ts = 246.515564 current_seq = 8884 count = 110 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.515991 last_received_ts = 246.515564 last_seq = 8884 current_ts = 246.532639 current_received_ts = 246.532150 current_seq = 8885 count = 111 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.532639 last_received_ts = 246.532150 last_seq = 8885 current_ts = 246.549255 current_received_ts = 246.548828 current_seq = 8886 count = 112 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.549255 last_received_ts = 246.548828 last_seq = 8886 current_ts = 246.565887 current_received_ts = 246.565460 current_seq = 8887 count = 113 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.565887 last_received_ts = 246.565460 last_seq = 8887 current_ts = 246.582520 current_received_ts = 246.582108 current_seq = 8888 count = 114 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.582520 last_received_ts = 246.582108 last_seq = 8888 current_ts = 246.599167 current_received_ts = 246.598724 current_seq = 8889 count = 115 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.599167 last_received_ts = 246.598724 last_seq = 8889 current_ts = 246.615799 current_received_ts = 246.615356 current_seq = 8890 count = 116 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.615799 last_received_ts = 246.615356 last_seq = 8890 current_ts = 246.632431 current_received_ts = 246.631989 current_seq = 8891 count = 117 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.632431 last_received_ts = 246.631989 last_seq = 8891 current_ts = 246.649063 current_received_ts = 246.648621 current_seq = 8892 count = 118 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.649063 last_received_ts = 246.648621 last_seq = 8892 current_ts = 246.665695 current_received_ts = 246.665176 current_seq = 8893 count = 119 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.665695 last_received_ts = 246.665176 last_seq = 8893 current_ts = 246.682327 current_received_ts = 246.681900 current_seq = 8894 count = 120 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.682327 last_received_ts = 246.681900 last_seq = 8894 current_ts = 246.698959 current_received_ts = 246.698532 current_seq = 8895 count = 121 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.698959 last_received_ts = 246.698532 last_seq = 8895 current_ts = 246.715607 current_received_ts = 246.715134 current_seq = 8896 count = 122 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.715607 last_received_ts = 246.715134 last_seq = 8896 current_ts = 246.732224 current_received_ts = 246.731796 current_seq = 8897 count = 123 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.732224 last_received_ts = 246.731796 last_seq = 8897 current_ts = 246.748856 current_received_ts = 246.748428 current_seq = 8898 count = 124 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.748856 last_received_ts = 246.748428 last_seq = 8898 current_ts = 246.765488 current_received_ts = 246.765076 current_seq = 8899 count = 125 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.765488 last_received_ts = 246.765076 last_seq = 8899 current_ts = 246.782120 current_received_ts = 246.781693 current_seq = 8900 count = 126 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.782120 last_received_ts = 246.781693 last_seq = 8900 current_ts = 246.798752 current_received_ts = 246.798309 current_seq = 8901 count = 127 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.798752 last_received_ts = 246.798309 last_seq = 8901 current_ts = 246.815384 current_received_ts = 246.814957 current_seq = 8902 count = 128 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.815384 last_received_ts = 246.814957 last_seq = 8902 current_ts = 246.832031 current_received_ts = 246.831558 current_seq = 8903 count = 129 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.832031 last_received_ts = 246.831558 last_seq = 8903 current_ts = 246.848663 current_received_ts = 246.848206 current_seq = 8904 count = 130 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.848663 last_received_ts = 246.848206 last_seq = 8904 current_ts = 246.865295 current_received_ts = 246.864792 current_seq = 8905 count = 131 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.865295 last_received_ts = 246.864792 last_seq = 8905 current_ts = 246.881927 current_received_ts = 246.881454 current_seq = 8906 count = 132 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.881927 last_received_ts = 246.881454 last_seq = 8906 current_ts = 246.898560 current_received_ts = 246.898117 current_seq = 8907 count = 133 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.898560 last_received_ts = 246.898117 last_seq = 8907 current_ts = 246.915192 current_received_ts = 246.914749 current_seq = 8908 count = 134 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.915192 last_received_ts = 246.914749 last_seq = 8908 current_ts = 246.931824 current_received_ts = 246.931381 current_seq = 8909 count = 135 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.931824 last_received_ts = 246.931381 last_seq = 8909 current_ts = 246.948471 current_received_ts = 246.948029 current_seq = 8910 count = 136 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 4us (kms_flip:18417) DEBUG: name = flip last_ts = 246.948471 last_received_ts = 246.948029 last_seq = 8910 current_ts = 246.965088 current_received_ts = 246.964691 current_seq = 8911 count = 137 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.965088 last_received_ts = 246.964691 last_seq = 8911 current_ts = 246.981720 current_received_ts = 246.981293 current_seq = 8912 count = 138 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 246.981720 last_received_ts = 246.981293 last_seq = 8912 current_ts = 246.998352 current_received_ts = 246.997925 current_seq = 8913 count = 139 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 246.998352 last_received_ts = 246.997925 last_seq = 8913 current_ts = 247.014984 current_received_ts = 247.014496 current_seq = 8914 count = 140 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.014984 last_received_ts = 247.014496 last_seq = 8914 current_ts = 247.031616 current_received_ts = 247.031189 current_seq = 8915 count = 141 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.031616 last_received_ts = 247.031189 last_seq = 8915 current_ts = 247.048248 current_received_ts = 247.047821 current_seq = 8916 count = 142 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.048248 last_received_ts = 247.047821 last_seq = 8916 current_ts = 247.064896 current_received_ts = 247.064362 current_seq = 8917 count = 143 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.064896 last_received_ts = 247.064362 last_seq = 8917 current_ts = 247.081528 current_received_ts = 247.081100 current_seq = 8918 count = 144 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.081528 last_received_ts = 247.081100 last_seq = 8918 current_ts = 247.098160 current_received_ts = 247.097717 current_seq = 8919 count = 145 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.098160 last_received_ts = 247.097717 last_seq = 8919 current_ts = 247.114792 current_received_ts = 247.114349 current_seq = 8920 count = 146 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.114792 last_received_ts = 247.114349 last_seq = 8920 current_ts = 247.131424 current_received_ts = 247.130981 current_seq = 8921 count = 147 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.131424 last_received_ts = 247.130981 last_seq = 8921 current_ts = 247.148056 current_received_ts = 247.147614 current_seq = 8922 count = 148 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.148056 last_received_ts = 247.147614 last_seq = 8922 current_ts = 247.164688 current_received_ts = 247.164246 current_seq = 8923 count = 149 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.164688 last_received_ts = 247.164246 last_seq = 8923 current_ts = 247.181320 current_received_ts = 247.180878 current_seq = 8924 count = 150 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.181320 last_received_ts = 247.180878 last_seq = 8924 current_ts = 247.197952 current_received_ts = 247.197510 current_seq = 8925 count = 151 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.197952 last_received_ts = 247.197510 last_seq = 8925 current_ts = 247.214584 current_received_ts = 247.214142 current_seq = 8926 count = 152 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.214584 last_received_ts = 247.214142 last_seq = 8926 current_ts = 247.231216 current_received_ts = 247.230759 current_seq = 8927 count = 153 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 9us (kms_flip:18417) DEBUG: name = flip last_ts = 247.231216 last_received_ts = 247.230759 last_seq = 8927 current_ts = 247.247849 current_received_ts = 247.247391 current_seq = 8928 count = 154 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.247849 last_received_ts = 247.247391 last_seq = 8928 current_ts = 247.264496 current_received_ts = 247.263977 current_seq = 8929 count = 155 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.264496 last_received_ts = 247.263977 last_seq = 8929 current_ts = 247.281113 current_received_ts = 247.280685 current_seq = 8930 count = 156 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.281113 last_received_ts = 247.280685 last_seq = 8930 current_ts = 247.297745 current_received_ts = 247.297318 current_seq = 8931 count = 157 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.297745 last_received_ts = 247.297318 last_seq = 8931 current_ts = 247.314377 current_received_ts = 247.313950 current_seq = 8932 count = 158 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.314377 last_received_ts = 247.313950 last_seq = 8932 current_ts = 247.331024 current_received_ts = 247.330582 current_seq = 8933 count = 159 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.331024 last_received_ts = 247.330582 last_seq = 8933 current_ts = 247.347656 current_received_ts = 247.347214 current_seq = 8934 count = 160 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.347656 last_received_ts = 247.347214 last_seq = 8934 current_ts = 247.364288 current_received_ts = 247.363846 current_seq = 8935 count = 161 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.364288 last_received_ts = 247.363846 last_seq = 8935 current_ts = 247.380920 current_received_ts = 247.380478 current_seq = 8936 count = 162 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.380920 last_received_ts = 247.380478 last_seq = 8936 current_ts = 247.397552 current_received_ts = 247.397110 current_seq = 8937 count = 163 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.397552 last_received_ts = 247.397110 last_seq = 8937 current_ts = 247.414185 current_received_ts = 247.413727 current_seq = 8938 count = 164 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.414185 last_received_ts = 247.413727 last_seq = 8938 current_ts = 247.430817 current_received_ts = 247.430359 current_seq = 8939 count = 165 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.430817 last_received_ts = 247.430359 last_seq = 8939 current_ts = 247.447449 current_received_ts = 247.447037 current_seq = 8940 count = 166 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.447449 last_received_ts = 247.447037 last_seq = 8940 current_ts = 247.464081 current_received_ts = 247.463623 current_seq = 8941 count = 167 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.464081 last_received_ts = 247.463623 last_seq = 8941 current_ts = 247.480713 current_received_ts = 247.480286 current_seq = 8942 count = 168 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.480713 last_received_ts = 247.480286 last_seq = 8942 current_ts = 247.497345 current_received_ts = 247.496902 current_seq = 8943 count = 169 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.497345 last_received_ts = 247.496902 last_seq = 8943 current_ts = 247.513977 current_received_ts = 247.513535 current_seq = 8944 count = 170 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.513977 last_received_ts = 247.513535 last_seq = 8944 current_ts = 247.530609 current_received_ts = 247.530167 current_seq = 8945 count = 171 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.530609 last_received_ts = 247.530167 last_seq = 8945 current_ts = 247.547241 current_received_ts = 247.546814 current_seq = 8946 count = 172 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.547241 last_received_ts = 247.546814 last_seq = 8946 current_ts = 247.563873 current_received_ts = 247.563446 current_seq = 8947 count = 173 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.563873 last_received_ts = 247.563446 last_seq = 8947 current_ts = 247.580505 current_received_ts = 247.580093 current_seq = 8948 count = 174 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.580505 last_received_ts = 247.580093 last_seq = 8948 current_ts = 247.597153 current_received_ts = 247.596710 current_seq = 8949 count = 175 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.597153 last_received_ts = 247.596710 last_seq = 8949 current_ts = 247.613785 current_received_ts = 247.613342 current_seq = 8950 count = 176 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.613785 last_received_ts = 247.613342 last_seq = 8950 current_ts = 247.630417 current_received_ts = 247.629959 current_seq = 8951 count = 177 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.630417 last_received_ts = 247.629959 last_seq = 8951 current_ts = 247.647049 current_received_ts = 247.646606 current_seq = 8952 count = 178 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.647049 last_received_ts = 247.646606 last_seq = 8952 current_ts = 247.663681 current_received_ts = 247.663177 current_seq = 8953 count = 179 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 6us (kms_flip:18417) DEBUG: name = flip last_ts = 247.663681 last_received_ts = 247.663177 last_seq = 8953 current_ts = 247.680313 current_received_ts = 247.679871 current_seq = 8954 count = 180 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.680313 last_received_ts = 247.679871 last_seq = 8954 current_ts = 247.696945 current_received_ts = 247.696503 current_seq = 8955 count = 181 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.696945 last_received_ts = 247.696503 last_seq = 8955 current_ts = 247.713577 current_received_ts = 247.713150 current_seq = 8956 count = 182 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.713577 last_received_ts = 247.713150 last_seq = 8956 current_ts = 247.730209 current_received_ts = 247.729767 current_seq = 8957 count = 183 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.730209 last_received_ts = 247.729767 last_seq = 8957 current_ts = 247.746841 current_received_ts = 247.746399 current_seq = 8958 count = 184 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.746841 last_received_ts = 247.746399 last_seq = 8958 current_ts = 247.763474 current_received_ts = 247.763062 current_seq = 8959 count = 185 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.763474 last_received_ts = 247.763062 last_seq = 8959 current_ts = 247.780106 current_received_ts = 247.779648 current_seq = 8960 count = 186 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 9us (kms_flip:18417) DEBUG: name = flip last_ts = 247.780106 last_received_ts = 247.779648 last_seq = 8960 current_ts = 247.796738 current_received_ts = 247.796310 current_seq = 8961 count = 187 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.796738 last_received_ts = 247.796310 last_seq = 8961 current_ts = 247.813370 current_received_ts = 247.812943 current_seq = 8962 count = 188 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.813370 last_received_ts = 247.812943 last_seq = 8962 current_ts = 247.830017 current_received_ts = 247.829559 current_seq = 8963 count = 189 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 9us (kms_flip:18417) DEBUG: name = flip last_ts = 247.830017 last_received_ts = 247.829559 last_seq = 8963 current_ts = 247.846649 current_received_ts = 247.846176 current_seq = 8964 count = 190 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.846649 last_received_ts = 247.846176 last_seq = 8964 current_ts = 247.863281 current_received_ts = 247.862839 current_seq = 8965 count = 191 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.863281 last_received_ts = 247.862839 last_seq = 8965 current_ts = 247.879913 current_received_ts = 247.879456 current_seq = 8966 count = 192 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.879913 last_received_ts = 247.879456 last_seq = 8966 current_ts = 247.896545 current_received_ts = 247.896103 current_seq = 8967 count = 193 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 7us (kms_flip:18417) DEBUG: name = flip last_ts = 247.896545 last_received_ts = 247.896103 last_seq = 8967 current_ts = 247.913177 current_received_ts = 247.912735 current_seq = 8968 count = 194 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.913177 last_received_ts = 247.912735 last_seq = 8968 current_ts = 247.929810 current_received_ts = 247.929382 current_seq = 8969 count = 195 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 8us (kms_flip:18417) DEBUG: name = flip last_ts = 247.929810 last_received_ts = 247.929382 last_seq = 8969 current_ts = 247.946442 current_received_ts = 247.946030 current_seq = 8970 count = 196 seq_step = 1 (kms_flip:18417) DEBUG: Vblank took 553us (kms_flip:18417) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:930: (kms_flip:18417) CRITICAL: Failed assertion: end - start < 500 (kms_flip:18417) igt_core-INFO: Stack trace: (kms_flip:18417) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:18417) igt_core-INFO: #1 ../tests/kms_flip.c:925 run_test_on_crtc_set.constprop.0() (kms_flip:18417) igt_core-INFO: #2 ../tests/kms_flip.c:1891 run_test() (kms_flip:18417) igt_core-INFO: #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047() (kms_flip:18417) igt_core-INFO: #4 ../tests/kms_flip.c:2047 main() (kms_flip:18417) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:18417) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:18417) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A1: FAIL (3.863s)
Dmesg	<6> [244.462075] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1 <7> [244.462585] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:90] <7> [244.462717] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:92] <7> [244.515689] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A] <7> [244.516054] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:72:pipe B] <7> [244.516253] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.enable (expected yes, found no) <7> [244.516791] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.active (expected yes, found no) <7> [244.517423] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1) <7> [244.518020] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in has_pch_encoder (expected yes, found no) <7> [244.518543] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in fdi_lanes (expected 1, found 0) <7> [244.519044] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0) <7> [244.519450] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in output_types (expected 0x00000002, found 0x00000000) <7> [244.519823] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [244.520364] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1024, found 0) <7> [244.520687] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 1344, found 0) <7> [244.521007] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1024, found 0) <7> [244.521267] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 1344, found 0) <7> [244.521496] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 1048, found 0) <7> [244.521727] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 1184, found 0) <7> [244.522009] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 768, found 0) <7> [244.522260] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 768, found 0) <7> [244.522490] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 771, found 0) <7> [244.522720] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 777, found 0) <7> [244.522990] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 806, found 0) <7> [244.523240] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 806, found 0) <7> [244.523469] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1024, found 0) <7> [244.523699] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 1344, found 0) <7> [244.523968] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1024, found 0) <7> [244.524223] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 1344, found 0) <7> [244.524469] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 1048, found 0) <7> [244.524698] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 1184, found 0) <7> [244.524974] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 768, found 0) <7> [244.525235] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 768, found 0) <7> [244.525465] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 771, found 0) <7> [244.525694] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 777, found 0) <7> [244.525959] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 806, found 0) <7> [244.526227] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 806, found 0) <7> [244.526456] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [244.526686] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [244.526975] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [244.527223] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [244.527453] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 64800, found 0) <7> [244.527683] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 64800, found 0) <7> [244.527937] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in port_clock (expected 64800, found 0) <7> [244.528196] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:72:pipe B] fastset requirement not met, forcing full modeset <7> [244.528427] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:72:pipe B] releasing PCH DPLL A <7> [244.528679] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:72:pipe B] min cdclk: 72000 kHz -> 0 kHz <7> [244.528947] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:72:pipe B] enable: no [modeset] <7> [244.529177] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:primary B] fb: [NOFB], visible: no <7> [244.529932] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B <7> [244.543469] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found <7> [244.544032] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found <7> [244.544553] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found <7> [244.561333] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x2, on? 1) for [CRTC:72:pipe B] <7> [244.561850] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A <7> [244.562596] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT] <7> [244.563106] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D] <7> [244.563583] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D] <7> [244.564098] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:73:VGA-1] <7> [244.564417] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:72:pipe B] <7> [244.564757] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A] <7> [244.564788] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:76:HDMI-A-1] <7> [244.564894] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [244.565171] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:53:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [244.565410] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3 <7> [244.565642] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [244.565879] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [244.566143] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [244.566406] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes) <7> [244.566643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3) <7> [244.566879] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288) <7> [244.567139] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [244.567400] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [244.567631] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [244.567861] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [244.568193] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [244.568425] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [244.568655] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [244.568885] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [244.569154] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [244.569384] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [244.569624] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [244.569861] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [244.570132] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [244.570452] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [244.570702] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [244.570962] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [244.571193] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [244.571423] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [244.571660] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [244.571937] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [244.572179] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [244.572491] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [244.572784] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [244.573065] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [244.573296] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [244.573526] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [244.573756] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [244.574043] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [244.574285] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [244.574523] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [244.574838] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [244.575108] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in has_infoframe (expected no, found yes) <7> [244.575339] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in dpll_hw_state <7> [244.575569] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [244.575798] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09 <7> [244.576078] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [244.576318] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06 <7> [244.576548] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [244.576853] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800) <7> [244.577161] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800) <7> [244.577399] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in port_clock (expected 0, found 223200) <7> [244.577630] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [244.577860] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [244.578137] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in avi infoframe <7> [244.578385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [244.578613] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [244.578853] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [244.578855] i915 0000:00:02.0: colorspace: RGB <7> [244.578858] i915 0000:00:02.0: scan mode: Underscan <7> [244.578860] i915 0000:00:02.0: colorimetry: No Data <7> [244.578862] i915 0000:00:02.0: picture aspect: No Data <7> [244.578864] i915 0000:00:02.0: active aspect: Same as Picture <7> [244.578866] i915 0000:00:02.0: itc: No Data <7> [244.578868] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [244.578870] i915 0000:00:02.0: quantization range: Full <7> [244.578872] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [244.578874] i915 0000:00:02.0: video code: 0 <7> [244.578876] i915 0000:00:02.0: ycc quantization range: Full <7> [244.578878] i915 0000:00:02.0: hdmi content type: Graphics <7> [244.578880] i915 0000:00:02.0: pixel repeat: 0 <7> [244.578882] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [244.578884] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in spd infoframe <7> [244.579138] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [244.579367] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [244.579596] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [244.579598] i915 0000:00:02.0: vendor: Intel <7> [244.579600] i915 0000:00:02.0: product: Integrated gfx <7> [244.579602] i915 0000:00:02.0: source device information: PC General (0x9) <7> [244.579605] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in hdmi infoframe <7> [244.579834] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [244.580098] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [244.580346] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [244.580348] i915 0000:00:02.0: empty frame <7> [244.580351] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:53:pipe A] fastset requirement not met, forcing full modeset <7> [244.580610] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:53:pipe A] min cdclk: 0 kHz -> 165334 kHz <7> [244.580840] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:53:pipe A] allocated PCH DPLL A <7> [244.581140] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:53:pipe A] reserving PCH DPLL A <7> [244.581403] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:53:pipe A] enable: yes [modeset] <7> [244.581647] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [244.581882] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0 <7> [244.582135] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [244.582174] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on <7> [244.582371] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [244.582605] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [244.582839] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [244.583090] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64 <7> [244.583326] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [244.583560] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [244.583794] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [244.583796] i915 0000:00:02.0: colorspace: RGB <7> [244.583799] i915 0000:00:02.0: scan mode: Underscan <7> [244.583800] i915 0000:00:02.0: colorimetry: No Data <7> [244.583802] i915 0000:00:02.0: picture aspect: No Data <7> [244.583804] i915 0000:00:02.0: active aspect: Same as Picture <7> [244.583806] i915 0000:00:02.0: itc: No Data <7> [244.583808] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [244.583810] i915 0000:00:02.0: quantization range: Full <7> [244.583812] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [244.583814] i915 0000:00:02.0: video code: 0 <7> [244.583816] i915 0000:00:02.0: ycc quantization range: Full <7> [244.583818] i915 0000:00:02.0: hdmi content type: Graphics <7> [244.583820] i915 0000:00:02.0: pixel repeat: 0 <7> [244.583821] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [244.583824] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [244.583826] i915 0000:00:02.0: vendor: Intel <7> [244.583828] i915 0000:00:02.0: product: Integrated gfx <7> [244.583830] i915 0000:00:02.0: source device information: PC General (0x9) <7> [244.583832] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [244.583834] i915 0000:00:02.0: empty frame <7> [244.583836] 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> [244.584078] 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> [244.584313] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1 <7> [244.584547] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [244.584781] 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> [244.585035] 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> [244.585270] 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> [244.585504] 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> [244.585740] 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> [244.585992] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [244.586229] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [244.586464] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [244.586699] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pixel rate 148800, min cdclk 165334, min voltage level 0 <7> [244.586940] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0 <7> [244.587174] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [244.587415] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [244.587654] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [244.587888] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [244.588136] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06 <7> [244.588364] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [244.588592] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [244.588820] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [244.589079] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.589424] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.589775] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [244.590104] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:primary A] fb: [FB:90] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [244.590385] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [244.590614] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [244.592894] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on <7> [244.593165] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT] <7> [244.593399] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D] <7> [244.593694] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D] <7> [244.594716] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [244.595821] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100 <7> [244.596112] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done. <7> [244.597126] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x600 <7> [244.597357] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done. <7> [244.597582] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done. <7> [244.597811] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:53:pipe A] <7> [244.598068] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A <7> [244.649873] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:76:HDMI-A-1][ENCODER:75:HDMI D] Enable audio codec on [CRTC:53:pipe A], 32 bytes ELD <7> [244.666495] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults <7> [244.667028] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000) <7> [244.667519] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:76:HDMI-A-1] <7> [244.668091] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:53:pipe A] <6> [248.325358] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL

Detail

Value

Duration

3.86 seconds

Hostname

shard-snb6

Igt-Version

IGT-Version: 2.4-g1295cc9cf (x86_64) (Linux: 7.0.0-rc6-CI_DRM_18267-gf1d4727d10d2+ x86_64)

Out

Starting dynamic subtest: A-HDMI-A1
  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:925 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1891 run_test()
  #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047()
  #4 ../tests/kms_flip.c:2047 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A1: FAIL (3.863s)

Err

Starting dynamic subtest: A-HDMI-A1
(kms_flip:18417) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:930:
(kms_flip:18417) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-HDMI-A1 failed.
**** DEBUG ****
(kms_flip:18417) DEBUG: name = flip
last_ts = 245.917206
last_received_ts = 245.916733
last_seq = 8848
current_ts = 245.933838
current_received_ts = 245.933365
current_seq = 8849
count = 75
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 245.933838
last_received_ts = 245.933365
last_seq = 8849
current_ts = 245.950470
current_received_ts = 245.949997
current_seq = 8850
count = 76
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 245.950470
last_received_ts = 245.949997
last_seq = 8850
current_ts = 245.967102
current_received_ts = 245.966629
current_seq = 8851
count = 77
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 245.967102
last_received_ts = 245.966629
last_seq = 8851
current_ts = 245.983734
current_received_ts = 245.983261
current_seq = 8852
count = 78
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 245.983734
last_received_ts = 245.983261
last_seq = 8852
current_ts = 246.000366
current_received_ts = 245.999908
current_seq = 8853
count = 79
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.000366
last_received_ts = 245.999908
last_seq = 8853
current_ts = 246.017014
current_received_ts = 246.016510
current_seq = 8854
count = 80
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.017014
last_received_ts = 246.016510
last_seq = 8854
current_ts = 246.033646
current_received_ts = 246.033142
current_seq = 8855
count = 81
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.033646
last_received_ts = 246.033142
last_seq = 8855
current_ts = 246.050262
current_received_ts = 246.049805
current_seq = 8856
count = 82
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.050262
last_received_ts = 246.049805
last_seq = 8856
current_ts = 246.066910
current_received_ts = 246.066437
current_seq = 8857
count = 83
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.066910
last_received_ts = 246.066437
last_seq = 8857
current_ts = 246.083542
current_received_ts = 246.083069
current_seq = 8858
count = 84
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.083542
last_received_ts = 246.083069
last_seq = 8858
current_ts = 246.100174
current_received_ts = 246.099701
current_seq = 8859
count = 85
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.100174
last_received_ts = 246.099701
last_seq = 8859
current_ts = 246.116806
current_received_ts = 246.116333
current_seq = 8860
count = 86
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.116806
last_received_ts = 246.116333
last_seq = 8860
current_ts = 246.133438
current_received_ts = 246.132965
current_seq = 8861
count = 87
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.133438
last_received_ts = 246.132965
last_seq = 8861
current_ts = 246.150070
current_received_ts = 246.149612
current_seq = 8862
count = 88
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.150070
last_received_ts = 246.149612
last_seq = 8862
current_ts = 246.166702
current_received_ts = 246.166229
current_seq = 8863
count = 89
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.166702
last_received_ts = 246.166229
last_seq = 8863
current_ts = 246.183334
current_received_ts = 246.182861
current_seq = 8864
count = 90
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.183334
last_received_ts = 246.182861
last_seq = 8864
current_ts = 246.199966
current_received_ts = 246.199493
current_seq = 8865
count = 91
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.199966
last_received_ts = 246.199493
last_seq = 8865
current_ts = 246.216599
current_received_ts = 246.216080
current_seq = 8866
count = 92
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.216599
last_received_ts = 246.216080
last_seq = 8866
current_ts = 246.233231
current_received_ts = 246.232742
current_seq = 8867
count = 93
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.233231
last_received_ts = 246.232742
last_seq = 8867
current_ts = 246.249863
current_received_ts = 246.249374
current_seq = 8868
count = 94
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.249863
last_received_ts = 246.249374
last_seq = 8868
current_ts = 246.266495
current_received_ts = 246.266037
current_seq = 8869
count = 95
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 9us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.266495
last_received_ts = 246.266037
last_seq = 8869
current_ts = 246.283127
current_received_ts = 246.282669
current_seq = 8870
count = 96
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.283127
last_received_ts = 246.282669
last_seq = 8870
current_ts = 246.299774
current_received_ts = 246.299301
current_seq = 8871
count = 97
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.299774
last_received_ts = 246.299301
last_seq = 8871
current_ts = 246.316406
current_received_ts = 246.315918
current_seq = 8872
count = 98
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.316406
last_received_ts = 246.315918
last_seq = 8872
current_ts = 246.333038
current_received_ts = 246.332596
current_seq = 8873
count = 99
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.333038
last_received_ts = 246.332596
last_seq = 8873
current_ts = 246.349670
current_received_ts = 246.349197
current_seq = 8874
count = 100
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.349670
last_received_ts = 246.349197
last_seq = 8874
current_ts = 246.366302
current_received_ts = 246.365875
current_seq = 8875
count = 101
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.366302
last_received_ts = 246.365875
last_seq = 8875
current_ts = 246.382935
current_received_ts = 246.382507
current_seq = 8876
count = 102
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.382935
last_received_ts = 246.382507
last_seq = 8876
current_ts = 246.399567
current_received_ts = 246.399124
current_seq = 8877
count = 103
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.399567
last_received_ts = 246.399124
last_seq = 8877
current_ts = 246.416199
current_received_ts = 246.415771
current_seq = 8878
count = 104
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.416199
last_received_ts = 246.415771
last_seq = 8878
current_ts = 246.432831
current_received_ts = 246.432373
current_seq = 8879
count = 105
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.432831
last_received_ts = 246.432373
last_seq = 8879
current_ts = 246.449463
current_received_ts = 246.449036
current_seq = 8880
count = 106
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.449463
last_received_ts = 246.449036
last_seq = 8880
current_ts = 246.466095
current_received_ts = 246.465668
current_seq = 8881
count = 107
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.466095
last_received_ts = 246.465668
last_seq = 8881
current_ts = 246.482727
current_received_ts = 246.482300
current_seq = 8882
count = 108
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.482727
last_received_ts = 246.482300
last_seq = 8882
current_ts = 246.499359
current_received_ts = 246.498932
current_seq = 8883
count = 109
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.499359
last_received_ts = 246.498932
last_seq = 8883
current_ts = 246.515991
current_received_ts = 246.515564
current_seq = 8884
count = 110
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.515991
last_received_ts = 246.515564
last_seq = 8884
current_ts = 246.532639
current_received_ts = 246.532150
current_seq = 8885
count = 111
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.532639
last_received_ts = 246.532150
last_seq = 8885
current_ts = 246.549255
current_received_ts = 246.548828
current_seq = 8886
count = 112
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.549255
last_received_ts = 246.548828
last_seq = 8886
current_ts = 246.565887
current_received_ts = 246.565460
current_seq = 8887
count = 113
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.565887
last_received_ts = 246.565460
last_seq = 8887
current_ts = 246.582520
current_received_ts = 246.582108
current_seq = 8888
count = 114
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.582520
last_received_ts = 246.582108
last_seq = 8888
current_ts = 246.599167
current_received_ts = 246.598724
current_seq = 8889
count = 115
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.599167
last_received_ts = 246.598724
last_seq = 8889
current_ts = 246.615799
current_received_ts = 246.615356
current_seq = 8890
count = 116
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.615799
last_received_ts = 246.615356
last_seq = 8890
current_ts = 246.632431
current_received_ts = 246.631989
current_seq = 8891
count = 117
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.632431
last_received_ts = 246.631989
last_seq = 8891
current_ts = 246.649063
current_received_ts = 246.648621
current_seq = 8892
count = 118
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.649063
last_received_ts = 246.648621
last_seq = 8892
current_ts = 246.665695
current_received_ts = 246.665176
current_seq = 8893
count = 119
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.665695
last_received_ts = 246.665176
last_seq = 8893
current_ts = 246.682327
current_received_ts = 246.681900
current_seq = 8894
count = 120
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.682327
last_received_ts = 246.681900
last_seq = 8894
current_ts = 246.698959
current_received_ts = 246.698532
current_seq = 8895
count = 121
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.698959
last_received_ts = 246.698532
last_seq = 8895
current_ts = 246.715607
current_received_ts = 246.715134
current_seq = 8896
count = 122
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.715607
last_received_ts = 246.715134
last_seq = 8896
current_ts = 246.732224
current_received_ts = 246.731796
current_seq = 8897
count = 123
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.732224
last_received_ts = 246.731796
last_seq = 8897
current_ts = 246.748856
current_received_ts = 246.748428
current_seq = 8898
count = 124
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.748856
last_received_ts = 246.748428
last_seq = 8898
current_ts = 246.765488
current_received_ts = 246.765076
current_seq = 8899
count = 125
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.765488
last_received_ts = 246.765076
last_seq = 8899
current_ts = 246.782120
current_received_ts = 246.781693
current_seq = 8900
count = 126
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.782120
last_received_ts = 246.781693
last_seq = 8900
current_ts = 246.798752
current_received_ts = 246.798309
current_seq = 8901
count = 127
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.798752
last_received_ts = 246.798309
last_seq = 8901
current_ts = 246.815384
current_received_ts = 246.814957
current_seq = 8902
count = 128
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.815384
last_received_ts = 246.814957
last_seq = 8902
current_ts = 246.832031
current_received_ts = 246.831558
current_seq = 8903
count = 129
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.832031
last_received_ts = 246.831558
last_seq = 8903
current_ts = 246.848663
current_received_ts = 246.848206
current_seq = 8904
count = 130
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.848663
last_received_ts = 246.848206
last_seq = 8904
current_ts = 246.865295
current_received_ts = 246.864792
current_seq = 8905
count = 131
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.865295
last_received_ts = 246.864792
last_seq = 8905
current_ts = 246.881927
current_received_ts = 246.881454
current_seq = 8906
count = 132
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.881927
last_received_ts = 246.881454
last_seq = 8906
current_ts = 246.898560
current_received_ts = 246.898117
current_seq = 8907
count = 133
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.898560
last_received_ts = 246.898117
last_seq = 8907
current_ts = 246.915192
current_received_ts = 246.914749
current_seq = 8908
count = 134
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.915192
last_received_ts = 246.914749
last_seq = 8908
current_ts = 246.931824
current_received_ts = 246.931381
current_seq = 8909
count = 135
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.931824
last_received_ts = 246.931381
last_seq = 8909
current_ts = 246.948471
current_received_ts = 246.948029
current_seq = 8910
count = 136
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 4us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.948471
last_received_ts = 246.948029
last_seq = 8910
current_ts = 246.965088
current_received_ts = 246.964691
current_seq = 8911
count = 137
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.965088
last_received_ts = 246.964691
last_seq = 8911
current_ts = 246.981720
current_received_ts = 246.981293
current_seq = 8912
count = 138
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.981720
last_received_ts = 246.981293
last_seq = 8912
current_ts = 246.998352
current_received_ts = 246.997925
current_seq = 8913
count = 139
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 246.998352
last_received_ts = 246.997925
last_seq = 8913
current_ts = 247.014984
current_received_ts = 247.014496
current_seq = 8914
count = 140
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.014984
last_received_ts = 247.014496
last_seq = 8914
current_ts = 247.031616
current_received_ts = 247.031189
current_seq = 8915
count = 141
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.031616
last_received_ts = 247.031189
last_seq = 8915
current_ts = 247.048248
current_received_ts = 247.047821
current_seq = 8916
count = 142
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.048248
last_received_ts = 247.047821
last_seq = 8916
current_ts = 247.064896
current_received_ts = 247.064362
current_seq = 8917
count = 143
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.064896
last_received_ts = 247.064362
last_seq = 8917
current_ts = 247.081528
current_received_ts = 247.081100
current_seq = 8918
count = 144
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.081528
last_received_ts = 247.081100
last_seq = 8918
current_ts = 247.098160
current_received_ts = 247.097717
current_seq = 8919
count = 145
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.098160
last_received_ts = 247.097717
last_seq = 8919
current_ts = 247.114792
current_received_ts = 247.114349
current_seq = 8920
count = 146
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.114792
last_received_ts = 247.114349
last_seq = 8920
current_ts = 247.131424
current_received_ts = 247.130981
current_seq = 8921
count = 147
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.131424
last_received_ts = 247.130981
last_seq = 8921
current_ts = 247.148056
current_received_ts = 247.147614
current_seq = 8922
count = 148
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.148056
last_received_ts = 247.147614
last_seq = 8922
current_ts = 247.164688
current_received_ts = 247.164246
current_seq = 8923
count = 149
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.164688
last_received_ts = 247.164246
last_seq = 8923
current_ts = 247.181320
current_received_ts = 247.180878
current_seq = 8924
count = 150
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.181320
last_received_ts = 247.180878
last_seq = 8924
current_ts = 247.197952
current_received_ts = 247.197510
current_seq = 8925
count = 151
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.197952
last_received_ts = 247.197510
last_seq = 8925
current_ts = 247.214584
current_received_ts = 247.214142
current_seq = 8926
count = 152
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.214584
last_received_ts = 247.214142
last_seq = 8926
current_ts = 247.231216
current_received_ts = 247.230759
current_seq = 8927
count = 153
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 9us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.231216
last_received_ts = 247.230759
last_seq = 8927
current_ts = 247.247849
current_received_ts = 247.247391
current_seq = 8928
count = 154
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.247849
last_received_ts = 247.247391
last_seq = 8928
current_ts = 247.264496
current_received_ts = 247.263977
current_seq = 8929
count = 155
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.264496
last_received_ts = 247.263977
last_seq = 8929
current_ts = 247.281113
current_received_ts = 247.280685
current_seq = 8930
count = 156
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.281113
last_received_ts = 247.280685
last_seq = 8930
current_ts = 247.297745
current_received_ts = 247.297318
current_seq = 8931
count = 157
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.297745
last_received_ts = 247.297318
last_seq = 8931
current_ts = 247.314377
current_received_ts = 247.313950
current_seq = 8932
count = 158
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.314377
last_received_ts = 247.313950
last_seq = 8932
current_ts = 247.331024
current_received_ts = 247.330582
current_seq = 8933
count = 159
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.331024
last_received_ts = 247.330582
last_seq = 8933
current_ts = 247.347656
current_received_ts = 247.347214
current_seq = 8934
count = 160
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.347656
last_received_ts = 247.347214
last_seq = 8934
current_ts = 247.364288
current_received_ts = 247.363846
current_seq = 8935
count = 161
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.364288
last_received_ts = 247.363846
last_seq = 8935
current_ts = 247.380920
current_received_ts = 247.380478
current_seq = 8936
count = 162
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.380920
last_received_ts = 247.380478
last_seq = 8936
current_ts = 247.397552
current_received_ts = 247.397110
current_seq = 8937
count = 163
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.397552
last_received_ts = 247.397110
last_seq = 8937
current_ts = 247.414185
current_received_ts = 247.413727
current_seq = 8938
count = 164
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.414185
last_received_ts = 247.413727
last_seq = 8938
current_ts = 247.430817
current_received_ts = 247.430359
current_seq = 8939
count = 165
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.430817
last_received_ts = 247.430359
last_seq = 8939
current_ts = 247.447449
current_received_ts = 247.447037
current_seq = 8940
count = 166
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.447449
last_received_ts = 247.447037
last_seq = 8940
current_ts = 247.464081
current_received_ts = 247.463623
current_seq = 8941
count = 167
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.464081
last_received_ts = 247.463623
last_seq = 8941
current_ts = 247.480713
current_received_ts = 247.480286
current_seq = 8942
count = 168
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.480713
last_received_ts = 247.480286
last_seq = 8942
current_ts = 247.497345
current_received_ts = 247.496902
current_seq = 8943
count = 169
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.497345
last_received_ts = 247.496902
last_seq = 8943
current_ts = 247.513977
current_received_ts = 247.513535
current_seq = 8944
count = 170
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.513977
last_received_ts = 247.513535
last_seq = 8944
current_ts = 247.530609
current_received_ts = 247.530167
current_seq = 8945
count = 171
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.530609
last_received_ts = 247.530167
last_seq = 8945
current_ts = 247.547241
current_received_ts = 247.546814
current_seq = 8946
count = 172
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.547241
last_received_ts = 247.546814
last_seq = 8946
current_ts = 247.563873
current_received_ts = 247.563446
current_seq = 8947
count = 173
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.563873
last_received_ts = 247.563446
last_seq = 8947
current_ts = 247.580505
current_received_ts = 247.580093
current_seq = 8948
count = 174
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.580505
last_received_ts = 247.580093
last_seq = 8948
current_ts = 247.597153
current_received_ts = 247.596710
current_seq = 8949
count = 175
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.597153
last_received_ts = 247.596710
last_seq = 8949
current_ts = 247.613785
current_received_ts = 247.613342
current_seq = 8950
count = 176
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.613785
last_received_ts = 247.613342
last_seq = 8950
current_ts = 247.630417
current_received_ts = 247.629959
current_seq = 8951
count = 177
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.630417
last_received_ts = 247.629959
last_seq = 8951
current_ts = 247.647049
current_received_ts = 247.646606
current_seq = 8952
count = 178
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.647049
last_received_ts = 247.646606
last_seq = 8952
current_ts = 247.663681
current_received_ts = 247.663177
current_seq = 8953
count = 179
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 6us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.663681
last_received_ts = 247.663177
last_seq = 8953
current_ts = 247.680313
current_received_ts = 247.679871
current_seq = 8954
count = 180
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.680313
last_received_ts = 247.679871
last_seq = 8954
current_ts = 247.696945
current_received_ts = 247.696503
current_seq = 8955
count = 181
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.696945
last_received_ts = 247.696503
last_seq = 8955
current_ts = 247.713577
current_received_ts = 247.713150
current_seq = 8956
count = 182
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.713577
last_received_ts = 247.713150
last_seq = 8956
current_ts = 247.730209
current_received_ts = 247.729767
current_seq = 8957
count = 183
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.730209
last_received_ts = 247.729767
last_seq = 8957
current_ts = 247.746841
current_received_ts = 247.746399
current_seq = 8958
count = 184
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.746841
last_received_ts = 247.746399
last_seq = 8958
current_ts = 247.763474
current_received_ts = 247.763062
current_seq = 8959
count = 185
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.763474
last_received_ts = 247.763062
last_seq = 8959
current_ts = 247.780106
current_received_ts = 247.779648
current_seq = 8960
count = 186
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 9us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.780106
last_received_ts = 247.779648
last_seq = 8960
current_ts = 247.796738
current_received_ts = 247.796310
current_seq = 8961
count = 187
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.796738
last_received_ts = 247.796310
last_seq = 8961
current_ts = 247.813370
current_received_ts = 247.812943
current_seq = 8962
count = 188
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.813370
last_received_ts = 247.812943
last_seq = 8962
current_ts = 247.830017
current_received_ts = 247.829559
current_seq = 8963
count = 189
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 9us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.830017
last_received_ts = 247.829559
last_seq = 8963
current_ts = 247.846649
current_received_ts = 247.846176
current_seq = 8964
count = 190
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.846649
last_received_ts = 247.846176
last_seq = 8964
current_ts = 247.863281
current_received_ts = 247.862839
current_seq = 8965
count = 191
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.863281
last_received_ts = 247.862839
last_seq = 8965
current_ts = 247.879913
current_received_ts = 247.879456
current_seq = 8966
count = 192
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.879913
last_received_ts = 247.879456
last_seq = 8966
current_ts = 247.896545
current_received_ts = 247.896103
current_seq = 8967
count = 193
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 7us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.896545
last_received_ts = 247.896103
last_seq = 8967
current_ts = 247.913177
current_received_ts = 247.912735
current_seq = 8968
count = 194
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.913177
last_received_ts = 247.912735
last_seq = 8968
current_ts = 247.929810
current_received_ts = 247.929382
current_seq = 8969
count = 195
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 8us
(kms_flip:18417) DEBUG: name = flip
last_ts = 247.929810
last_received_ts = 247.929382
last_seq = 8969
current_ts = 247.946442
current_received_ts = 247.946030
current_seq = 8970
count = 196
seq_step = 1
(kms_flip:18417) DEBUG: Vblank took 553us
(kms_flip:18417) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:930:
(kms_flip:18417) CRITICAL: Failed assertion: end - start < 500
(kms_flip:18417) igt_core-INFO: Stack trace:
(kms_flip:18417) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:18417) igt_core-INFO:   #1 ../tests/kms_flip.c:925 run_test_on_crtc_set.constprop.0()
(kms_flip:18417) igt_core-INFO:   #2 ../tests/kms_flip.c:1891 run_test()
(kms_flip:18417) igt_core-INFO:   #3 ../tests/kms_flip.c:2126 __igt_unique____real_main2047()
(kms_flip:18417) igt_core-INFO:   #4 ../tests/kms_flip.c:2047 main()
(kms_flip:18417) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:18417) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:18417) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A1: FAIL (3.863s)

Dmesg

<6> [244.462075] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1

<7> [244.462585] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:90]

<7> [244.462717] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:92]

<7> [244.515689] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A]

<7> [244.516054] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:72:pipe B]

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

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

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

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

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

<7> [244.519044] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:72:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.528427] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:72:pipe B] releasing PCH DPLL A

<7> [244.528679] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:72:pipe B] min cdclk: 72000 kHz -> 0 kHz

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

<7> [244.529177] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:primary B] fb: [NOFB], visible: no

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

<7> [244.543469] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found

<7> [244.544032] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found

<7> [244.544553] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found

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

<7> [244.561850] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A

<7> [244.562596] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT]

<7> [244.563106] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D]

<7> [244.563583] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D]

<7> [244.564098] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:73:VGA-1]

<7> [244.564417] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:72:pipe B]

<7> [244.564757] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:53:pipe A]

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

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

<7> [244.565171] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:53:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0

<7> [244.565410] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3

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

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

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

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

<7> [244.566643] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3)

<7> [244.566879] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.575339] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:53:pipe A] fastset requirement not met in dpll_hw_state

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

<7> [244.575798] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09

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

<7> [244.576318] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.580610] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:53:pipe A] min cdclk: 0 kHz -> 165334 kHz

<7> [244.580840] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:53:pipe A] allocated PCH DPLL A

<7> [244.581140] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:53:pipe A] reserving PCH DPLL A

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

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

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

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

<7> [244.582174] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on

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

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

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

<7> [244.583090] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [244.583836] 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> [244.584078] 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> [244.584313] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1

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

<7> [244.584781] 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> [244.585035] 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> [244.585270] 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> [244.585504] 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> [244.585740] 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> [244.585992] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9

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

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

<7> [244.586699] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pixel rate 148800, min cdclk 165334, min voltage level 0

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

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

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

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

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

<7> [244.588136] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06

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

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

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

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

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

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

<7> [244.590104] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:primary A] fb: [FB:90] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes

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

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

<7> [244.592894] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on

<7> [244.593165] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:CRT]

<7> [244.593399] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:75:HDMI D]

<7> [244.593694] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:83:DP D]

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

<7> [244.595821] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100

<7> [244.596112] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done.

<7> [244.597126] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x600

<7> [244.597357] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done.

<7> [244.597582] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done.

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

<7> [244.598068] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A

<7> [244.649873] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:76:HDMI-A-1][ENCODER:75:HDMI D] Enable audio codec on [CRTC:53:pipe A], 32 bytes ELD

<7> [244.666495] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults

<7> [244.667028] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000)

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

<7> [244.668091] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:53:pipe A]

<6> [248.325358] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL

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