igt@kms_flip@flip-vs-expired-vblank@b-hdmi-a4 on shard-dg1@CI_DRM

Detail	Value
Duration	2.98 seconds
Hostname	shard-dg1-17
Igt-Version	IGT-Version: 2.3-gf38f4d8e9 (x86_64) (Linux: 6.19.0-rc1-CI_DRM_17725-g50dc58765da3+ x86_64)
Out	Starting dynamic subtest: B-HDMI-A4 1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1889 run_test() #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045() #4 ../tests/kms_flip.c:2045 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest B-HDMI-A4: FAIL (2.975s)
Err	Starting dynamic subtest: B-HDMI-A4 (kms_flip:2130) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2130) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest B-HDMI-A4 failed. ** DEBUG (kms_flip:2130) DEBUG: name = flip last_ts = 134.635345 last_received_ts = 134.634933 last_seq = 58 current_ts = 134.652008 current_received_ts = 134.651596 current_seq = 59 count = 21 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 134.652008 last_received_ts = 134.651596 last_seq = 59 current_ts = 134.668671 current_received_ts = 134.668274 current_seq = 60 count = 22 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 134.668671 last_received_ts = 134.668274 last_seq = 60 current_ts = 134.685349 current_received_ts = 134.684921 current_seq = 61 count = 23 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 86us (kms_flip:2130) DEBUG: name = flip last_ts = 134.685349 last_received_ts = 134.684921 last_seq = 61 current_ts = 134.702011 current_received_ts = 134.701584 current_seq = 62 count = 24 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 134.702011 last_received_ts = 134.701584 last_seq = 62 current_ts = 134.718674 current_received_ts = 134.718292 current_seq = 63 count = 25 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 134.718674 last_received_ts = 134.718292 last_seq = 63 current_ts = 134.735352 current_received_ts = 134.734924 current_seq = 64 count = 26 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 92us (kms_flip:2130) DEBUG: name = flip last_ts = 134.735352 last_received_ts = 134.734924 last_seq = 64 current_ts = 134.752014 current_received_ts = 134.751587 current_seq = 65 count = 27 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 134.752014 last_received_ts = 134.751587 last_seq = 65 current_ts = 134.768677 current_received_ts = 134.768280 current_seq = 66 count = 28 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 134.768677 last_received_ts = 134.768280 last_seq = 66 current_ts = 134.785339 current_received_ts = 134.784927 current_seq = 67 count = 29 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 86us (kms_flip:2130) DEBUG: name = flip last_ts = 134.785339 last_received_ts = 134.784927 last_seq = 67 current_ts = 134.802017 current_received_ts = 134.801590 current_seq = 68 count = 30 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 134.802017 last_received_ts = 134.801590 last_seq = 68 current_ts = 134.818680 current_received_ts = 134.818283 current_seq = 69 count = 31 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 134.818680 last_received_ts = 134.818283 last_seq = 69 current_ts = 134.835342 current_received_ts = 134.834930 current_seq = 70 count = 32 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 87us (kms_flip:2130) DEBUG: name = flip last_ts = 134.835342 last_received_ts = 134.834930 last_seq = 70 current_ts = 134.852005 current_received_ts = 134.851578 current_seq = 71 count = 33 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 134.852005 last_received_ts = 134.851578 last_seq = 71 current_ts = 134.868683 current_received_ts = 134.868256 current_seq = 72 count = 34 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 134.868683 last_received_ts = 134.868256 last_seq = 72 current_ts = 134.885345 current_received_ts = 134.884918 current_seq = 73 count = 35 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 87us (kms_flip:2130) DEBUG: name = flip last_ts = 134.885345 last_received_ts = 134.884918 last_seq = 73 current_ts = 134.902008 current_received_ts = 134.901596 current_seq = 74 count = 36 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 134.902008 last_received_ts = 134.901596 last_seq = 74 current_ts = 134.918671 current_received_ts = 134.918289 current_seq = 75 count = 37 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 134.918671 last_received_ts = 134.918289 last_seq = 75 current_ts = 134.935349 current_received_ts = 134.934937 current_seq = 76 count = 38 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 88us (kms_flip:2130) DEBUG: name = flip last_ts = 134.935349 last_received_ts = 134.934937 last_seq = 76 current_ts = 134.952011 current_received_ts = 134.951599 current_seq = 77 count = 39 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 134.952011 last_received_ts = 134.951599 last_seq = 77 current_ts = 134.968674 current_received_ts = 134.968277 current_seq = 78 count = 40 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 134.968674 last_received_ts = 134.968277 last_seq = 78 current_ts = 134.985336 current_received_ts = 134.984940 current_seq = 79 count = 41 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 92us (kms_flip:2130) DEBUG: name = flip last_ts = 134.985336 last_received_ts = 134.984940 last_seq = 79 current_ts = 135.002014 current_received_ts = 135.001602 current_seq = 80 count = 42 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.002014 last_received_ts = 135.001602 last_seq = 80 current_ts = 135.018661 current_received_ts = 135.018280 current_seq = 81 count = 43 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.018661 last_received_ts = 135.018280 last_seq = 81 current_ts = 135.035339 current_received_ts = 135.034927 current_seq = 82 count = 44 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 86us (kms_flip:2130) DEBUG: name = flip last_ts = 135.035339 last_received_ts = 135.034927 last_seq = 82 current_ts = 135.052002 current_received_ts = 135.051590 current_seq = 83 count = 45 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 135.052002 last_received_ts = 135.051590 last_seq = 83 current_ts = 135.068665 current_received_ts = 135.068268 current_seq = 84 count = 46 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.068665 last_received_ts = 135.068268 last_seq = 84 current_ts = 135.085342 current_received_ts = 135.084930 current_seq = 85 count = 47 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 92us (kms_flip:2130) DEBUG: name = flip last_ts = 135.085342 last_received_ts = 135.084930 last_seq = 85 current_ts = 135.102005 current_received_ts = 135.101593 current_seq = 86 count = 48 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.102005 last_received_ts = 135.101593 last_seq = 86 current_ts = 135.118668 current_received_ts = 135.118286 current_seq = 87 count = 49 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.118668 last_received_ts = 135.118286 last_seq = 87 current_ts = 135.135345 current_received_ts = 135.134933 current_seq = 88 count = 50 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 96us (kms_flip:2130) DEBUG: name = flip last_ts = 135.135345 last_received_ts = 135.134933 last_seq = 88 current_ts = 135.152008 current_received_ts = 135.151596 current_seq = 89 count = 51 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.152008 last_received_ts = 135.151596 last_seq = 89 current_ts = 135.168655 current_received_ts = 135.168289 current_seq = 90 count = 52 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.168655 last_received_ts = 135.168289 last_seq = 90 current_ts = 135.185333 current_received_ts = 135.184921 current_seq = 91 count = 53 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 93us (kms_flip:2130) DEBUG: name = flip last_ts = 135.185333 last_received_ts = 135.184921 last_seq = 91 current_ts = 135.202011 current_received_ts = 135.201599 current_seq = 92 count = 54 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 135.202011 last_received_ts = 135.201599 last_seq = 92 current_ts = 135.218658 current_received_ts = 135.218277 current_seq = 93 count = 55 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.218658 last_received_ts = 135.218277 last_seq = 93 current_ts = 135.235336 current_received_ts = 135.234924 current_seq = 94 count = 56 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 91us (kms_flip:2130) DEBUG: name = flip last_ts = 135.235336 last_received_ts = 135.234924 last_seq = 94 current_ts = 135.251999 current_received_ts = 135.251602 current_seq = 95 count = 57 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.251999 last_received_ts = 135.251602 last_seq = 95 current_ts = 135.268661 current_received_ts = 135.268280 current_seq = 96 count = 58 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.268661 last_received_ts = 135.268280 last_seq = 96 current_ts = 135.285339 current_received_ts = 135.284927 current_seq = 97 count = 59 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 88us (kms_flip:2130) DEBUG: name = flip last_ts = 135.285339 last_received_ts = 135.284927 last_seq = 97 current_ts = 135.302002 current_received_ts = 135.301590 current_seq = 98 count = 60 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.302002 last_received_ts = 135.301590 last_seq = 98 current_ts = 135.318665 current_received_ts = 135.318283 current_seq = 99 count = 61 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.318665 last_received_ts = 135.318283 last_seq = 99 current_ts = 135.335342 current_received_ts = 135.334915 current_seq = 100 count = 62 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 87us (kms_flip:2130) DEBUG: name = flip last_ts = 135.335342 last_received_ts = 135.334915 last_seq = 100 current_ts = 135.352005 current_received_ts = 135.351593 current_seq = 101 count = 63 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.352005 last_received_ts = 135.351593 last_seq = 101 current_ts = 135.368668 current_received_ts = 135.368286 current_seq = 102 count = 64 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.368668 last_received_ts = 135.368286 last_seq = 102 current_ts = 135.385330 current_received_ts = 135.384918 current_seq = 103 count = 65 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 88us (kms_flip:2130) DEBUG: name = flip last_ts = 135.385330 last_received_ts = 135.384918 last_seq = 103 current_ts = 135.401993 current_received_ts = 135.401581 current_seq = 104 count = 66 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.401993 last_received_ts = 135.401581 last_seq = 104 current_ts = 135.418655 current_received_ts = 135.418274 current_seq = 105 count = 67 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.418655 last_received_ts = 135.418274 last_seq = 105 current_ts = 135.435333 current_received_ts = 135.434921 current_seq = 106 count = 68 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 106us (kms_flip:2130) DEBUG: name = flip last_ts = 135.435333 last_received_ts = 135.434921 last_seq = 106 current_ts = 135.451996 current_received_ts = 135.451584 current_seq = 107 count = 69 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.451996 last_received_ts = 135.451584 last_seq = 107 current_ts = 135.468658 current_received_ts = 135.468277 current_seq = 108 count = 70 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.468658 last_received_ts = 135.468277 last_seq = 108 current_ts = 135.485336 current_received_ts = 135.484924 current_seq = 109 count = 71 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 85us (kms_flip:2130) DEBUG: name = flip last_ts = 135.485336 last_received_ts = 135.484924 last_seq = 109 current_ts = 135.501999 current_received_ts = 135.501587 current_seq = 110 count = 72 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.501999 last_received_ts = 135.501587 last_seq = 110 current_ts = 135.518661 current_received_ts = 135.518265 current_seq = 111 count = 73 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.518661 last_received_ts = 135.518265 last_seq = 111 current_ts = 135.535324 current_received_ts = 135.534912 current_seq = 112 count = 74 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 88us (kms_flip:2130) DEBUG: name = flip last_ts = 135.535324 last_received_ts = 135.534912 last_seq = 112 current_ts = 135.552002 current_received_ts = 135.551590 current_seq = 113 count = 75 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.552002 last_received_ts = 135.551590 last_seq = 113 current_ts = 135.568665 current_received_ts = 135.568268 current_seq = 114 count = 76 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.568665 last_received_ts = 135.568268 last_seq = 114 current_ts = 135.585327 current_received_ts = 135.584915 current_seq = 115 count = 77 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 85us (kms_flip:2130) DEBUG: name = flip last_ts = 135.585327 last_received_ts = 135.584915 last_seq = 115 current_ts = 135.601990 current_received_ts = 135.601593 current_seq = 116 count = 78 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.601990 last_received_ts = 135.601593 last_seq = 116 current_ts = 135.618668 current_received_ts = 135.618271 current_seq = 117 count = 79 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.618668 last_received_ts = 135.618271 last_seq = 117 current_ts = 135.635330 current_received_ts = 135.634918 current_seq = 118 count = 80 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 85us (kms_flip:2130) DEBUG: name = flip last_ts = 135.635330 last_received_ts = 135.634918 last_seq = 118 current_ts = 135.651993 current_received_ts = 135.651581 current_seq = 119 count = 81 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.651993 last_received_ts = 135.651581 last_seq = 119 current_ts = 135.668655 current_received_ts = 135.668259 current_seq = 120 count = 82 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.668655 last_received_ts = 135.668259 last_seq = 120 current_ts = 135.685333 current_received_ts = 135.684921 current_seq = 121 count = 83 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 85us (kms_flip:2130) DEBUG: name = flip last_ts = 135.685333 last_received_ts = 135.684921 last_seq = 121 current_ts = 135.701996 current_received_ts = 135.701584 current_seq = 122 count = 84 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 135.701996 last_received_ts = 135.701584 last_seq = 122 current_ts = 135.718658 current_received_ts = 135.718262 current_seq = 123 count = 85 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.718658 last_received_ts = 135.718262 last_seq = 123 current_ts = 135.735321 current_received_ts = 135.734909 current_seq = 124 count = 86 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 84us (kms_flip:2130) DEBUG: name = flip last_ts = 135.735321 last_received_ts = 135.734909 last_seq = 124 current_ts = 135.751999 current_received_ts = 135.751602 current_seq = 125 count = 87 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.751999 last_received_ts = 135.751602 last_seq = 125 current_ts = 135.768661 current_received_ts = 135.768280 current_seq = 126 count = 88 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.768661 last_received_ts = 135.768280 last_seq = 126 current_ts = 135.785324 current_received_ts = 135.784912 current_seq = 127 count = 89 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.785324 last_received_ts = 135.784912 last_seq = 127 current_ts = 135.801987 current_received_ts = 135.801575 current_seq = 128 count = 90 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.801987 last_received_ts = 135.801575 last_seq = 128 current_ts = 135.818649 current_received_ts = 135.818253 current_seq = 129 count = 91 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.818649 last_received_ts = 135.818253 last_seq = 129 current_ts = 135.835327 current_received_ts = 135.834915 current_seq = 130 count = 92 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 85us (kms_flip:2130) DEBUG: name = flip last_ts = 135.835327 last_received_ts = 135.834915 last_seq = 130 current_ts = 135.851990 current_received_ts = 135.851578 current_seq = 131 count = 93 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.851990 last_received_ts = 135.851578 last_seq = 131 current_ts = 135.868652 current_received_ts = 135.868256 current_seq = 132 count = 94 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.868652 last_received_ts = 135.868256 last_seq = 132 current_ts = 135.885330 current_received_ts = 135.884918 current_seq = 133 count = 95 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 95us (kms_flip:2130) DEBUG: name = flip last_ts = 135.885330 last_received_ts = 135.884918 last_seq = 133 current_ts = 135.901993 current_received_ts = 135.901581 current_seq = 134 count = 96 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.901993 last_received_ts = 135.901581 last_seq = 134 current_ts = 135.918655 current_received_ts = 135.918259 current_seq = 135 count = 97 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 135.918655 last_received_ts = 135.918259 last_seq = 135 current_ts = 135.935318 current_received_ts = 135.934906 current_seq = 136 count = 98 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 135.935318 last_received_ts = 135.934906 last_seq = 136 current_ts = 135.951981 current_received_ts = 135.951508 current_seq = 137 count = 99 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 24us (kms_flip:2130) DEBUG: name = flip last_ts = 135.951981 last_received_ts = 135.951508 last_seq = 137 current_ts = 135.968658 current_received_ts = 135.968170 current_seq = 138 count = 100 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 27us (kms_flip:2130) DEBUG: name = flip last_ts = 135.968658 last_received_ts = 135.968170 last_seq = 138 current_ts = 135.985321 current_received_ts = 135.984833 current_seq = 139 count = 101 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 33us (kms_flip:2130) DEBUG: name = flip last_ts = 135.985321 last_received_ts = 135.984833 last_seq = 139 current_ts = 136.001984 current_received_ts = 136.001572 current_seq = 140 count = 102 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.001984 last_received_ts = 136.001572 last_seq = 140 current_ts = 136.018646 current_received_ts = 136.018250 current_seq = 141 count = 103 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.018646 last_received_ts = 136.018250 last_seq = 141 current_ts = 136.035324 current_received_ts = 136.034912 current_seq = 142 count = 104 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 87us (kms_flip:2130) DEBUG: name = flip last_ts = 136.035324 last_received_ts = 136.034912 last_seq = 142 current_ts = 136.051987 current_received_ts = 136.051575 current_seq = 143 count = 105 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 136.051987 last_received_ts = 136.051575 last_seq = 143 current_ts = 136.068649 current_received_ts = 136.068253 current_seq = 144 count = 106 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.068649 last_received_ts = 136.068253 last_seq = 144 current_ts = 136.085327 current_received_ts = 136.084900 current_seq = 145 count = 107 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.085327 last_received_ts = 136.084900 last_seq = 145 current_ts = 136.101990 current_received_ts = 136.101578 current_seq = 146 count = 108 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.101990 last_received_ts = 136.101578 last_seq = 146 current_ts = 136.118652 current_received_ts = 136.118256 current_seq = 147 count = 109 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.118652 last_received_ts = 136.118256 last_seq = 147 current_ts = 136.135315 current_received_ts = 136.134918 current_seq = 148 count = 110 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 90us (kms_flip:2130) DEBUG: name = flip last_ts = 136.135315 last_received_ts = 136.134918 last_seq = 148 current_ts = 136.151993 current_received_ts = 136.151581 current_seq = 149 count = 111 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.151993 last_received_ts = 136.151581 last_seq = 149 current_ts = 136.168640 current_received_ts = 136.168274 current_seq = 150 count = 112 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.168640 last_received_ts = 136.168274 last_seq = 150 current_ts = 136.185318 current_received_ts = 136.184906 current_seq = 151 count = 113 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 87us (kms_flip:2130) DEBUG: name = flip last_ts = 136.185318 last_received_ts = 136.184906 last_seq = 151 current_ts = 136.201981 current_received_ts = 136.201569 current_seq = 152 count = 114 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.201981 last_received_ts = 136.201569 last_seq = 152 current_ts = 136.218643 current_received_ts = 136.218262 current_seq = 153 count = 115 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.218643 last_received_ts = 136.218262 last_seq = 153 current_ts = 136.235321 current_received_ts = 136.234909 current_seq = 154 count = 116 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.235321 last_received_ts = 136.234909 last_seq = 154 current_ts = 136.251984 current_received_ts = 136.251572 current_seq = 155 count = 117 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.251984 last_received_ts = 136.251572 last_seq = 155 current_ts = 136.268646 current_received_ts = 136.268250 current_seq = 156 count = 118 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.268646 last_received_ts = 136.268250 last_seq = 156 current_ts = 136.285324 current_received_ts = 136.284912 current_seq = 157 count = 119 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.285324 last_received_ts = 136.284912 last_seq = 157 current_ts = 136.301987 current_received_ts = 136.301575 current_seq = 158 count = 120 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.301987 last_received_ts = 136.301575 last_seq = 158 current_ts = 136.318649 current_received_ts = 136.318253 current_seq = 159 count = 121 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.318649 last_received_ts = 136.318253 last_seq = 159 current_ts = 136.335312 current_received_ts = 136.334900 current_seq = 160 count = 122 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.335312 last_received_ts = 136.334900 last_seq = 160 current_ts = 136.351990 current_received_ts = 136.351578 current_seq = 161 count = 123 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.351990 last_received_ts = 136.351578 last_seq = 161 current_ts = 136.368637 current_received_ts = 136.368256 current_seq = 162 count = 124 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.368637 last_received_ts = 136.368256 last_seq = 162 current_ts = 136.385315 current_received_ts = 136.384903 current_seq = 163 count = 125 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 136.385315 last_received_ts = 136.384903 last_seq = 163 current_ts = 136.401978 current_received_ts = 136.401566 current_seq = 164 count = 126 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 136.401978 last_received_ts = 136.401566 last_seq = 164 current_ts = 136.418640 current_received_ts = 136.418243 current_seq = 165 count = 127 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.418640 last_received_ts = 136.418243 last_seq = 165 current_ts = 136.435318 current_received_ts = 136.434906 current_seq = 166 count = 128 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.435318 last_received_ts = 136.434906 last_seq = 166 current_ts = 136.451981 current_received_ts = 136.451569 current_seq = 167 count = 129 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.451981 last_received_ts = 136.451569 last_seq = 167 current_ts = 136.468643 current_received_ts = 136.468246 current_seq = 168 count = 130 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.468643 last_received_ts = 136.468246 last_seq = 168 current_ts = 136.485321 current_received_ts = 136.484909 current_seq = 169 count = 131 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.485321 last_received_ts = 136.484909 last_seq = 169 current_ts = 136.501984 current_received_ts = 136.501556 current_seq = 170 count = 132 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 136.501984 last_received_ts = 136.501556 last_seq = 170 current_ts = 136.518646 current_received_ts = 136.518250 current_seq = 171 count = 133 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.518646 last_received_ts = 136.518250 last_seq = 171 current_ts = 136.535309 current_received_ts = 136.534897 current_seq = 172 count = 134 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 56us (kms_flip:2130) DEBUG: name = flip last_ts = 136.535309 last_received_ts = 136.534897 last_seq = 172 current_ts = 136.551987 current_received_ts = 136.551575 current_seq = 173 count = 135 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.551987 last_received_ts = 136.551575 last_seq = 173 current_ts = 136.568634 current_received_ts = 136.568253 current_seq = 174 count = 136 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.568634 last_received_ts = 136.568253 last_seq = 174 current_ts = 136.585312 current_received_ts = 136.584900 current_seq = 175 count = 137 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 55us (kms_flip:2130) DEBUG: name = flip last_ts = 136.585312 last_received_ts = 136.584900 last_seq = 175 current_ts = 136.601990 current_received_ts = 136.601562 current_seq = 176 count = 138 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.601990 last_received_ts = 136.601562 last_seq = 176 current_ts = 136.618637 current_received_ts = 136.618195 current_seq = 177 count = 139 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 53us (kms_flip:2130) DEBUG: name = flip last_ts = 136.618637 last_received_ts = 136.618195 last_seq = 177 current_ts = 136.635315 current_received_ts = 136.635681 current_seq = 178 count = 140 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 53us (kms_flip:2130) DEBUG: name = flip last_ts = 136.635315 last_received_ts = 136.635681 last_seq = 178 current_ts = 136.651978 current_received_ts = 136.651550 current_seq = 179 count = 141 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 54us (kms_flip:2130) DEBUG: name = flip last_ts = 136.651978 last_received_ts = 136.651550 last_seq = 179 current_ts = 136.668640 current_received_ts = 136.668152 current_seq = 180 count = 142 seq_step = 1 (kms_flip:2130) DEBUG: Vblank took 2011us (kms_flip:2130) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2130) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2130) igt_core-INFO: Stack trace: (kms_flip:2130) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2130) igt_core-INFO: #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() (kms_flip:2130) igt_core-INFO: #2 ../tests/kms_flip.c:1889 run_test() (kms_flip:2130) igt_core-INFO: #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045() (kms_flip:2130) igt_core-INFO: #4 ../tests/kms_flip.c:2045 main() (kms_flip:2130) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2130) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2130) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-HDMI-A4: FAIL (2.975s)
Dmesg	<6> [134.119987] [IGT] kms_flip: starting dynamic subtest B-HDMI-A4 <7> [134.120421] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:635] <7> [134.120562] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:636] <7> [134.120875] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [134.121432] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [134.139942] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [134.140427] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [134.147263] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [134.147609] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [134.165535] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [134.165910] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [134.193015] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:169:pipe A] <7> [134.193178] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [134.193370] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [134.193539] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [134.193710] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [134.193878] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [134.194047] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [134.194264] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [134.194433] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [134.194602] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [134.194771] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [134.194940] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [134.195159] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [134.195328] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [134.195496] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [134.195664] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [134.195832] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [134.196000] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [134.196211] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [134.196380] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [134.196549] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [134.196718] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [134.196886] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [134.197055] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [134.197265] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [134.197434] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [134.197602] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [134.197769] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [134.197938] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [134.198146] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [134.198314] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [134.198482] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [134.198649] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [134.198817] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [134.198987] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [134.199192] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [134.199361] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [134.199529] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in port_clock (expected 148500, found 0) <7> [134.199699] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:169:pipe A] fastset requirement not met, forcing full modeset <7> [134.199867] i915 0000:03:00.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:169:pipe A] releasing DPLL 2 <7> [134.200085] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no <7> [134.200264] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:169:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [134.200467] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:163:cursor A] ddb (2012 - 2048) -> ( 0 - 0), size 36 -> 0 <7> [134.200664] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:169:pipe A] min cdclk: 74250 kHz -> 0 kHz <7> [134.200836] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:169:pipe A] enable: no [modeset] <7> [134.201004] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:plane 1A] fb: [NOFB], visible: no <7> [134.201330] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 2A] fb: [NOFB], visible: no <7> [134.201499] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:93:plane 3A] fb: [NOFB], visible: no <7> [134.201666] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:123:plane 4A] fb: [NOFB], visible: no <7> [134.201834] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:133:plane 5A] fb: [NOFB], visible: no <7> [134.202001] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:143:plane 6A] fb: [NOFB], visible: no <7> [134.202208] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 7A] fb: [NOFB], visible: no <7> [134.202375] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:163:cursor A] fb: [NOFB], visible: no <7> [134.202737] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A <7> [134.220283] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC2 <7> [134.220489] i915 0000:03:00.0: [drm:intel_dpll_disable [i915]] disable DPLL 2 (active 0x1, on? 1) for [CRTC:169:pipe A] <7> [134.220690] i915 0000:03:00.0: [drm:intel_dpll_disable [i915]] disabling DPLL 2 <7> [134.220880] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:585:DDI A/PHY A] <7> [134.221047] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:587:DP-MST A] <7> [134.221222] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:588:DP-MST B] <7> [134.221387] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:589:DP-MST C] <7> [134.221552] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:590:DP-MST D] <7> [134.221717] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:604:DDI B/PHY B] <7> [134.221881] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:608:DDI TC1/PHY C] <7> [134.222045] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:610:DP-MST A] <7> [134.222252] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:611:DP-MST B] <7> [134.222417] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:612:DP-MST C] <7> [134.222581] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:613:DP-MST D] <7> [134.222745] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:620:DDI TC2/PHY D] <7> [134.222930] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:622:DP-MST A] <7> [134.223133] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:623:DP-MST B] <7> [134.223299] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:624:DP-MST C] <7> [134.223464] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:625:DP-MST D] <7> [134.223628] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:629:HDMI-A-4] <7> [134.223910] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1 <7> [134.224178] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_3 <7> [134.224382] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2 <7> [134.224586] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:169:pipe A] <7> [134.225222] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:307:pipe B] <7> [134.225412] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:445:pipe C] <7> [134.225586] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:583:pipe D] <7> [134.225762] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:307:pipe B] <7> [134.225798] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:629:HDMI-A-4] <7> [134.225873] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CONNECTOR:629:HDMI-A-4] Limiting display bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36) <7> [134.226050] i915 0000:03:00.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24) <7> [134.226254] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:307:pipe B] hw max bpp: 24, pipe bpp: 24, dithering: 0 <7> [134.226425] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:620:DDI TC2/PHY D] [CRTC:307:pipe B] <7> [134.226585] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.enable (expected no, found yes) <7> [134.226755] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.active (expected no, found yes) <7> [134.226924] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1) <7> [134.227131] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in lane_count (expected 0, found 4) <7> [134.227299] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [134.227469] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [134.227637] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [134.227806] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [134.227974] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [134.228186] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [134.228355] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [134.228523] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [134.228691] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [134.228860] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [134.229028] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [134.229235] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [134.229404] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [134.229573] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [134.229740] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [134.229908] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [134.230103] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [134.230286] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [134.230454] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [134.230622] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [134.230790] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [134.230959] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [134.231165] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [134.231334] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [134.231503] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [134.231671] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [134.231840] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [134.232009] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [134.232218] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [134.232388] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [134.232556] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [134.232725] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [134.232894] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in port_clock (expected 0, found 148500) <7> [134.233068] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:307:pipe B] fastset requirement not met, forcing full modeset <7> [134.233299] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no <7> [134.233463] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:307:pipe B] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x2 <7> [134.233667] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:171:plane 1B] ddb ( 0 - 0) -> ( 0 - 2012), size 0 -> 2012 <7> [134.233830] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:301:cursor B] ddb ( 0 - 0) -> (2012 - 2048), size 0 -> 36 <7> [134.233991] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:171:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [134.234191] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:171:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 5, 5, 5, 8, 8, 9, 10, 0, 0, 0 <7> [134.234354] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:171:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 81, 81, 81, 129, 129, 145, 161, 30, 0, 0 <7> [134.234517] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:171:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 91, 91, 91, 143, 143, 161, 179, 31, 0, 0 <7> [134.234697] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:307:pipe B] data rate 594000 num active planes 1 <7> [134.234865] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 34000 required 594 <7> [134.235031] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1 <7> [134.235321] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:307:pipe B] min cdclk: 0 kHz -> 74250 kHz <7> [134.235508] i915 0000:03:00.0: [drm:intel_find_dpll [i915]] [CRTC:307:pipe B] allocated DPLL 2 <7> [134.235677] i915 0000:03:00.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:307:pipe B] reserving DPLL 2 <7> [134.235847] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:307:pipe B] enable: yes [modeset] <7> [134.236016] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [134.236223] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 24, dithering: 0 <7> [134.236391] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [134.236559] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [134.236725] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [134.236892] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [134.237064] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0 <7> [134.237270] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [134.237436] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [134.237603] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0 <7> [134.237771] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125 <7> [134.237938] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [134.238146] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [134.238314] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [134.238483] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 <7> [134.238651] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [134.238819] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 74250 <7> [134.238987] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0 <7> [134.239192] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [134.239361] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [134.239529] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [134.239696] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1001d0, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0 <7> [134.239864] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [134.240031] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [134.240236] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [134.240404] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [134.240570] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [134.240737] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [134.240904] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [134.241093] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [134.241274] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [134.241441] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [134.241608] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [134.241775] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [134.241941] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [134.242150] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:171:plane 1B] fb: [FB:635] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [134.242319] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [134.242487] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [134.242653] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:201:plane 2B] fb: [NOFB], visible: no <7> [134.242820] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:231:plane 3B] fb: [NOFB], visible: no <7> [134.242987] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:261:plane 4B] fb: [NOFB], visible: no <7> [134.243194] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 5B] fb: [NOFB], visible: no <7> [134.243362] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:281:plane 6B] fb: [NOFB], visible: no <7> [134.243529] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:291:plane 7B] fb: [NOFB], visible: no <7> [134.243696] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:cursor B] fb: [NOFB], visible: no <7> [134.244145] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2 <7> [134.244326] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_3 <7> [134.244537] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:585:DDI A/PHY A] <7> [134.244702] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:587:DP-MST A] <7> [134.244868] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:588:DP-MST B] <7> [134.245032] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:589:DP-MST C] <7> [134.245236] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:590:DP-MST D] <7> [134.245402] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:604:DDI B/PHY B] <7> [134.245567] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:608:DDI TC1/PHY C] <7> [134.245732] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:610:DP-MST A] <7> [134.245896] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:611:DP-MST B] <7> [134.246067] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:612:DP-MST C] <7> [134.246267] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:613:DP-MST D] <7> [134.246432] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:620:DDI TC2/PHY D] <7> [134.246596] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:622:DP-MST A] <7> [134.246761] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:623:DP-MST B] <7> [134.246927] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:624:DP-MST C] <7> [134.247139] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:625:DP-MST D] <7> [134.247381] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3 <7> [134.247596] i915 0000:03:00.0: [drm:intel_dpll_enable [i915]] enable DPLL 2 (active 0x2, on? 0) for [CRTC:307:pipe B] <7> [134.247765] i915 0000:03:00.0: [drm:intel_dpll_enable [i915]] enabling DPLL 2 <7> [134.247986] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC2 <7> [134.248270] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe B <7> [134.266380] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:629:HDMI-A-4] <7> [134.266667] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:307:pipe B] <6> [137.095518] [IGT] kms_flip: finished subtest B-HDMI-A4, FAIL

Detail

Value

Duration

2.98 seconds

Hostname

shard-dg1-17

Igt-Version

IGT-Version: 2.3-gf38f4d8e9 (x86_64) (Linux: 6.19.0-rc1-CI_DRM_17725-g50dc58765da3+ x86_64)

Out

Starting dynamic subtest: B-HDMI-A4
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1889 run_test()
  #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
  #4 ../tests/kms_flip.c:2045 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest B-HDMI-A4: FAIL (2.975s)

Err

Starting dynamic subtest: B-HDMI-A4
(kms_flip:2130) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2130) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest B-HDMI-A4 failed.
**** DEBUG ****
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.635345
last_received_ts = 134.634933
last_seq = 58
current_ts = 134.652008
current_received_ts = 134.651596
current_seq = 59
count = 21
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.652008
last_received_ts = 134.651596
last_seq = 59
current_ts = 134.668671
current_received_ts = 134.668274
current_seq = 60
count = 22
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.668671
last_received_ts = 134.668274
last_seq = 60
current_ts = 134.685349
current_received_ts = 134.684921
current_seq = 61
count = 23
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 86us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.685349
last_received_ts = 134.684921
last_seq = 61
current_ts = 134.702011
current_received_ts = 134.701584
current_seq = 62
count = 24
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.702011
last_received_ts = 134.701584
last_seq = 62
current_ts = 134.718674
current_received_ts = 134.718292
current_seq = 63
count = 25
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.718674
last_received_ts = 134.718292
last_seq = 63
current_ts = 134.735352
current_received_ts = 134.734924
current_seq = 64
count = 26
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 92us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.735352
last_received_ts = 134.734924
last_seq = 64
current_ts = 134.752014
current_received_ts = 134.751587
current_seq = 65
count = 27
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.752014
last_received_ts = 134.751587
last_seq = 65
current_ts = 134.768677
current_received_ts = 134.768280
current_seq = 66
count = 28
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.768677
last_received_ts = 134.768280
last_seq = 66
current_ts = 134.785339
current_received_ts = 134.784927
current_seq = 67
count = 29
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 86us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.785339
last_received_ts = 134.784927
last_seq = 67
current_ts = 134.802017
current_received_ts = 134.801590
current_seq = 68
count = 30
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.802017
last_received_ts = 134.801590
last_seq = 68
current_ts = 134.818680
current_received_ts = 134.818283
current_seq = 69
count = 31
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.818680
last_received_ts = 134.818283
last_seq = 69
current_ts = 134.835342
current_received_ts = 134.834930
current_seq = 70
count = 32
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 87us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.835342
last_received_ts = 134.834930
last_seq = 70
current_ts = 134.852005
current_received_ts = 134.851578
current_seq = 71
count = 33
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.852005
last_received_ts = 134.851578
last_seq = 71
current_ts = 134.868683
current_received_ts = 134.868256
current_seq = 72
count = 34
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.868683
last_received_ts = 134.868256
last_seq = 72
current_ts = 134.885345
current_received_ts = 134.884918
current_seq = 73
count = 35
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 87us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.885345
last_received_ts = 134.884918
last_seq = 73
current_ts = 134.902008
current_received_ts = 134.901596
current_seq = 74
count = 36
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.902008
last_received_ts = 134.901596
last_seq = 74
current_ts = 134.918671
current_received_ts = 134.918289
current_seq = 75
count = 37
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.918671
last_received_ts = 134.918289
last_seq = 75
current_ts = 134.935349
current_received_ts = 134.934937
current_seq = 76
count = 38
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 88us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.935349
last_received_ts = 134.934937
last_seq = 76
current_ts = 134.952011
current_received_ts = 134.951599
current_seq = 77
count = 39
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.952011
last_received_ts = 134.951599
last_seq = 77
current_ts = 134.968674
current_received_ts = 134.968277
current_seq = 78
count = 40
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.968674
last_received_ts = 134.968277
last_seq = 78
current_ts = 134.985336
current_received_ts = 134.984940
current_seq = 79
count = 41
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 92us
(kms_flip:2130) DEBUG: name = flip
last_ts = 134.985336
last_received_ts = 134.984940
last_seq = 79
current_ts = 135.002014
current_received_ts = 135.001602
current_seq = 80
count = 42
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.002014
last_received_ts = 135.001602
last_seq = 80
current_ts = 135.018661
current_received_ts = 135.018280
current_seq = 81
count = 43
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.018661
last_received_ts = 135.018280
last_seq = 81
current_ts = 135.035339
current_received_ts = 135.034927
current_seq = 82
count = 44
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 86us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.035339
last_received_ts = 135.034927
last_seq = 82
current_ts = 135.052002
current_received_ts = 135.051590
current_seq = 83
count = 45
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.052002
last_received_ts = 135.051590
last_seq = 83
current_ts = 135.068665
current_received_ts = 135.068268
current_seq = 84
count = 46
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.068665
last_received_ts = 135.068268
last_seq = 84
current_ts = 135.085342
current_received_ts = 135.084930
current_seq = 85
count = 47
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 92us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.085342
last_received_ts = 135.084930
last_seq = 85
current_ts = 135.102005
current_received_ts = 135.101593
current_seq = 86
count = 48
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.102005
last_received_ts = 135.101593
last_seq = 86
current_ts = 135.118668
current_received_ts = 135.118286
current_seq = 87
count = 49
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.118668
last_received_ts = 135.118286
last_seq = 87
current_ts = 135.135345
current_received_ts = 135.134933
current_seq = 88
count = 50
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 96us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.135345
last_received_ts = 135.134933
last_seq = 88
current_ts = 135.152008
current_received_ts = 135.151596
current_seq = 89
count = 51
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.152008
last_received_ts = 135.151596
last_seq = 89
current_ts = 135.168655
current_received_ts = 135.168289
current_seq = 90
count = 52
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.168655
last_received_ts = 135.168289
last_seq = 90
current_ts = 135.185333
current_received_ts = 135.184921
current_seq = 91
count = 53
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 93us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.185333
last_received_ts = 135.184921
last_seq = 91
current_ts = 135.202011
current_received_ts = 135.201599
current_seq = 92
count = 54
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.202011
last_received_ts = 135.201599
last_seq = 92
current_ts = 135.218658
current_received_ts = 135.218277
current_seq = 93
count = 55
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.218658
last_received_ts = 135.218277
last_seq = 93
current_ts = 135.235336
current_received_ts = 135.234924
current_seq = 94
count = 56
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 91us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.235336
last_received_ts = 135.234924
last_seq = 94
current_ts = 135.251999
current_received_ts = 135.251602
current_seq = 95
count = 57
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.251999
last_received_ts = 135.251602
last_seq = 95
current_ts = 135.268661
current_received_ts = 135.268280
current_seq = 96
count = 58
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.268661
last_received_ts = 135.268280
last_seq = 96
current_ts = 135.285339
current_received_ts = 135.284927
current_seq = 97
count = 59
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 88us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.285339
last_received_ts = 135.284927
last_seq = 97
current_ts = 135.302002
current_received_ts = 135.301590
current_seq = 98
count = 60
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.302002
last_received_ts = 135.301590
last_seq = 98
current_ts = 135.318665
current_received_ts = 135.318283
current_seq = 99
count = 61
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.318665
last_received_ts = 135.318283
last_seq = 99
current_ts = 135.335342
current_received_ts = 135.334915
current_seq = 100
count = 62
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 87us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.335342
last_received_ts = 135.334915
last_seq = 100
current_ts = 135.352005
current_received_ts = 135.351593
current_seq = 101
count = 63
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.352005
last_received_ts = 135.351593
last_seq = 101
current_ts = 135.368668
current_received_ts = 135.368286
current_seq = 102
count = 64
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.368668
last_received_ts = 135.368286
last_seq = 102
current_ts = 135.385330
current_received_ts = 135.384918
current_seq = 103
count = 65
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 88us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.385330
last_received_ts = 135.384918
last_seq = 103
current_ts = 135.401993
current_received_ts = 135.401581
current_seq = 104
count = 66
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.401993
last_received_ts = 135.401581
last_seq = 104
current_ts = 135.418655
current_received_ts = 135.418274
current_seq = 105
count = 67
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.418655
last_received_ts = 135.418274
last_seq = 105
current_ts = 135.435333
current_received_ts = 135.434921
current_seq = 106
count = 68
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 106us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.435333
last_received_ts = 135.434921
last_seq = 106
current_ts = 135.451996
current_received_ts = 135.451584
current_seq = 107
count = 69
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.451996
last_received_ts = 135.451584
last_seq = 107
current_ts = 135.468658
current_received_ts = 135.468277
current_seq = 108
count = 70
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.468658
last_received_ts = 135.468277
last_seq = 108
current_ts = 135.485336
current_received_ts = 135.484924
current_seq = 109
count = 71
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 85us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.485336
last_received_ts = 135.484924
last_seq = 109
current_ts = 135.501999
current_received_ts = 135.501587
current_seq = 110
count = 72
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.501999
last_received_ts = 135.501587
last_seq = 110
current_ts = 135.518661
current_received_ts = 135.518265
current_seq = 111
count = 73
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.518661
last_received_ts = 135.518265
last_seq = 111
current_ts = 135.535324
current_received_ts = 135.534912
current_seq = 112
count = 74
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 88us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.535324
last_received_ts = 135.534912
last_seq = 112
current_ts = 135.552002
current_received_ts = 135.551590
current_seq = 113
count = 75
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.552002
last_received_ts = 135.551590
last_seq = 113
current_ts = 135.568665
current_received_ts = 135.568268
current_seq = 114
count = 76
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.568665
last_received_ts = 135.568268
last_seq = 114
current_ts = 135.585327
current_received_ts = 135.584915
current_seq = 115
count = 77
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 85us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.585327
last_received_ts = 135.584915
last_seq = 115
current_ts = 135.601990
current_received_ts = 135.601593
current_seq = 116
count = 78
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.601990
last_received_ts = 135.601593
last_seq = 116
current_ts = 135.618668
current_received_ts = 135.618271
current_seq = 117
count = 79
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.618668
last_received_ts = 135.618271
last_seq = 117
current_ts = 135.635330
current_received_ts = 135.634918
current_seq = 118
count = 80
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 85us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.635330
last_received_ts = 135.634918
last_seq = 118
current_ts = 135.651993
current_received_ts = 135.651581
current_seq = 119
count = 81
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.651993
last_received_ts = 135.651581
last_seq = 119
current_ts = 135.668655
current_received_ts = 135.668259
current_seq = 120
count = 82
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.668655
last_received_ts = 135.668259
last_seq = 120
current_ts = 135.685333
current_received_ts = 135.684921
current_seq = 121
count = 83
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 85us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.685333
last_received_ts = 135.684921
last_seq = 121
current_ts = 135.701996
current_received_ts = 135.701584
current_seq = 122
count = 84
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.701996
last_received_ts = 135.701584
last_seq = 122
current_ts = 135.718658
current_received_ts = 135.718262
current_seq = 123
count = 85
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.718658
last_received_ts = 135.718262
last_seq = 123
current_ts = 135.735321
current_received_ts = 135.734909
current_seq = 124
count = 86
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 84us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.735321
last_received_ts = 135.734909
last_seq = 124
current_ts = 135.751999
current_received_ts = 135.751602
current_seq = 125
count = 87
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.751999
last_received_ts = 135.751602
last_seq = 125
current_ts = 135.768661
current_received_ts = 135.768280
current_seq = 126
count = 88
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.768661
last_received_ts = 135.768280
last_seq = 126
current_ts = 135.785324
current_received_ts = 135.784912
current_seq = 127
count = 89
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.785324
last_received_ts = 135.784912
last_seq = 127
current_ts = 135.801987
current_received_ts = 135.801575
current_seq = 128
count = 90
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.801987
last_received_ts = 135.801575
last_seq = 128
current_ts = 135.818649
current_received_ts = 135.818253
current_seq = 129
count = 91
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.818649
last_received_ts = 135.818253
last_seq = 129
current_ts = 135.835327
current_received_ts = 135.834915
current_seq = 130
count = 92
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 85us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.835327
last_received_ts = 135.834915
last_seq = 130
current_ts = 135.851990
current_received_ts = 135.851578
current_seq = 131
count = 93
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.851990
last_received_ts = 135.851578
last_seq = 131
current_ts = 135.868652
current_received_ts = 135.868256
current_seq = 132
count = 94
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.868652
last_received_ts = 135.868256
last_seq = 132
current_ts = 135.885330
current_received_ts = 135.884918
current_seq = 133
count = 95
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 95us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.885330
last_received_ts = 135.884918
last_seq = 133
current_ts = 135.901993
current_received_ts = 135.901581
current_seq = 134
count = 96
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.901993
last_received_ts = 135.901581
last_seq = 134
current_ts = 135.918655
current_received_ts = 135.918259
current_seq = 135
count = 97
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.918655
last_received_ts = 135.918259
last_seq = 135
current_ts = 135.935318
current_received_ts = 135.934906
current_seq = 136
count = 98
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.935318
last_received_ts = 135.934906
last_seq = 136
current_ts = 135.951981
current_received_ts = 135.951508
current_seq = 137
count = 99
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 24us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.951981
last_received_ts = 135.951508
last_seq = 137
current_ts = 135.968658
current_received_ts = 135.968170
current_seq = 138
count = 100
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 27us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.968658
last_received_ts = 135.968170
last_seq = 138
current_ts = 135.985321
current_received_ts = 135.984833
current_seq = 139
count = 101
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 33us
(kms_flip:2130) DEBUG: name = flip
last_ts = 135.985321
last_received_ts = 135.984833
last_seq = 139
current_ts = 136.001984
current_received_ts = 136.001572
current_seq = 140
count = 102
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.001984
last_received_ts = 136.001572
last_seq = 140
current_ts = 136.018646
current_received_ts = 136.018250
current_seq = 141
count = 103
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.018646
last_received_ts = 136.018250
last_seq = 141
current_ts = 136.035324
current_received_ts = 136.034912
current_seq = 142
count = 104
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 87us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.035324
last_received_ts = 136.034912
last_seq = 142
current_ts = 136.051987
current_received_ts = 136.051575
current_seq = 143
count = 105
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.051987
last_received_ts = 136.051575
last_seq = 143
current_ts = 136.068649
current_received_ts = 136.068253
current_seq = 144
count = 106
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.068649
last_received_ts = 136.068253
last_seq = 144
current_ts = 136.085327
current_received_ts = 136.084900
current_seq = 145
count = 107
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.085327
last_received_ts = 136.084900
last_seq = 145
current_ts = 136.101990
current_received_ts = 136.101578
current_seq = 146
count = 108
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.101990
last_received_ts = 136.101578
last_seq = 146
current_ts = 136.118652
current_received_ts = 136.118256
current_seq = 147
count = 109
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.118652
last_received_ts = 136.118256
last_seq = 147
current_ts = 136.135315
current_received_ts = 136.134918
current_seq = 148
count = 110
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 90us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.135315
last_received_ts = 136.134918
last_seq = 148
current_ts = 136.151993
current_received_ts = 136.151581
current_seq = 149
count = 111
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.151993
last_received_ts = 136.151581
last_seq = 149
current_ts = 136.168640
current_received_ts = 136.168274
current_seq = 150
count = 112
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.168640
last_received_ts = 136.168274
last_seq = 150
current_ts = 136.185318
current_received_ts = 136.184906
current_seq = 151
count = 113
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 87us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.185318
last_received_ts = 136.184906
last_seq = 151
current_ts = 136.201981
current_received_ts = 136.201569
current_seq = 152
count = 114
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.201981
last_received_ts = 136.201569
last_seq = 152
current_ts = 136.218643
current_received_ts = 136.218262
current_seq = 153
count = 115
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.218643
last_received_ts = 136.218262
last_seq = 153
current_ts = 136.235321
current_received_ts = 136.234909
current_seq = 154
count = 116
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.235321
last_received_ts = 136.234909
last_seq = 154
current_ts = 136.251984
current_received_ts = 136.251572
current_seq = 155
count = 117
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.251984
last_received_ts = 136.251572
last_seq = 155
current_ts = 136.268646
current_received_ts = 136.268250
current_seq = 156
count = 118
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.268646
last_received_ts = 136.268250
last_seq = 156
current_ts = 136.285324
current_received_ts = 136.284912
current_seq = 157
count = 119
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.285324
last_received_ts = 136.284912
last_seq = 157
current_ts = 136.301987
current_received_ts = 136.301575
current_seq = 158
count = 120
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.301987
last_received_ts = 136.301575
last_seq = 158
current_ts = 136.318649
current_received_ts = 136.318253
current_seq = 159
count = 121
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.318649
last_received_ts = 136.318253
last_seq = 159
current_ts = 136.335312
current_received_ts = 136.334900
current_seq = 160
count = 122
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.335312
last_received_ts = 136.334900
last_seq = 160
current_ts = 136.351990
current_received_ts = 136.351578
current_seq = 161
count = 123
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.351990
last_received_ts = 136.351578
last_seq = 161
current_ts = 136.368637
current_received_ts = 136.368256
current_seq = 162
count = 124
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.368637
last_received_ts = 136.368256
last_seq = 162
current_ts = 136.385315
current_received_ts = 136.384903
current_seq = 163
count = 125
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.385315
last_received_ts = 136.384903
last_seq = 163
current_ts = 136.401978
current_received_ts = 136.401566
current_seq = 164
count = 126
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.401978
last_received_ts = 136.401566
last_seq = 164
current_ts = 136.418640
current_received_ts = 136.418243
current_seq = 165
count = 127
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.418640
last_received_ts = 136.418243
last_seq = 165
current_ts = 136.435318
current_received_ts = 136.434906
current_seq = 166
count = 128
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.435318
last_received_ts = 136.434906
last_seq = 166
current_ts = 136.451981
current_received_ts = 136.451569
current_seq = 167
count = 129
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.451981
last_received_ts = 136.451569
last_seq = 167
current_ts = 136.468643
current_received_ts = 136.468246
current_seq = 168
count = 130
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.468643
last_received_ts = 136.468246
last_seq = 168
current_ts = 136.485321
current_received_ts = 136.484909
current_seq = 169
count = 131
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.485321
last_received_ts = 136.484909
last_seq = 169
current_ts = 136.501984
current_received_ts = 136.501556
current_seq = 170
count = 132
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.501984
last_received_ts = 136.501556
last_seq = 170
current_ts = 136.518646
current_received_ts = 136.518250
current_seq = 171
count = 133
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.518646
last_received_ts = 136.518250
last_seq = 171
current_ts = 136.535309
current_received_ts = 136.534897
current_seq = 172
count = 134
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 56us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.535309
last_received_ts = 136.534897
last_seq = 172
current_ts = 136.551987
current_received_ts = 136.551575
current_seq = 173
count = 135
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.551987
last_received_ts = 136.551575
last_seq = 173
current_ts = 136.568634
current_received_ts = 136.568253
current_seq = 174
count = 136
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.568634
last_received_ts = 136.568253
last_seq = 174
current_ts = 136.585312
current_received_ts = 136.584900
current_seq = 175
count = 137
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 55us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.585312
last_received_ts = 136.584900
last_seq = 175
current_ts = 136.601990
current_received_ts = 136.601562
current_seq = 176
count = 138
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.601990
last_received_ts = 136.601562
last_seq = 176
current_ts = 136.618637
current_received_ts = 136.618195
current_seq = 177
count = 139
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 53us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.618637
last_received_ts = 136.618195
last_seq = 177
current_ts = 136.635315
current_received_ts = 136.635681
current_seq = 178
count = 140
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 53us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.635315
last_received_ts = 136.635681
last_seq = 178
current_ts = 136.651978
current_received_ts = 136.651550
current_seq = 179
count = 141
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 54us
(kms_flip:2130) DEBUG: name = flip
last_ts = 136.651978
last_received_ts = 136.651550
last_seq = 179
current_ts = 136.668640
current_received_ts = 136.668152
current_seq = 180
count = 142
seq_step = 1
(kms_flip:2130) DEBUG: Vblank took 2011us
(kms_flip:2130) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2130) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2130) igt_core-INFO: Stack trace:
(kms_flip:2130) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2130) igt_core-INFO:   #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
(kms_flip:2130) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:2130) igt_core-INFO:   #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
(kms_flip:2130) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:2130) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2130) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2130) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-HDMI-A4: FAIL (2.975s)

Dmesg

<6> [134.119987] [IGT] kms_flip: starting dynamic subtest B-HDMI-A4

<7> [134.120421] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:635]

<7> [134.120562] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:636]

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

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

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

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

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

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

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

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

<7> [134.193015] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:169:pipe A]

<7> [134.193178] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.enable (expected yes, found no)

<7> [134.193370] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.active (expected yes, found no)

<7> [134.193539] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)

<7> [134.193710] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in lane_count (expected 4, found 0)

<7> [134.193878] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)

<7> [134.194047] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)

<7> [134.194264] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)

<7> [134.194433] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)

<7> [134.194602] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)

<7> [134.194771] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)

<7> [134.194940] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)

<7> [134.195159] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)

<7> [134.195328] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)

<7> [134.195496] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)

<7> [134.195664] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)

<7> [134.195832] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)

<7> [134.196000] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)

<7> [134.196211] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)

<7> [134.196380] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)

<7> [134.196549] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)

<7> [134.196718] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)

<7> [134.196886] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)

<7> [134.197055] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)

<7> [134.197265] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)

<7> [134.197434] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)

<7> [134.197602] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)

<7> [134.197769] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)

<7> [134.197938] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)

<7> [134.198146] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)

<7> [134.198314] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)

<7> [134.198482] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)

<7> [134.198649] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)

<7> [134.198817] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)

<7> [134.198987] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)

<7> [134.199192] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)

<7> [134.199361] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)

<7> [134.199529] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:169:pipe A] fastset requirement not met in port_clock (expected 148500, found 0)

<7> [134.199699] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:169:pipe A] fastset requirement not met, forcing full modeset

<7> [134.199867] i915 0000:03:00.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:169:pipe A] releasing DPLL 2

<7> [134.200085] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no

<7> [134.200264] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:169:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0

<7> [134.200467] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:163:cursor A] ddb (2012 - 2048) -> ( 0 - 0), size 36 -> 0

<7> [134.200664] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:169:pipe A] min cdclk: 74250 kHz -> 0 kHz

<7> [134.200836] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:169:pipe A] enable: no [modeset]

<7> [134.201004] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:plane 1A] fb: [NOFB], visible: no

<7> [134.201330] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 2A] fb: [NOFB], visible: no

<7> [134.201499] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:93:plane 3A] fb: [NOFB], visible: no

<7> [134.201666] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:123:plane 4A] fb: [NOFB], visible: no

<7> [134.201834] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:133:plane 5A] fb: [NOFB], visible: no

<7> [134.202001] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:143:plane 6A] fb: [NOFB], visible: no

<7> [134.202208] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:153:plane 7A] fb: [NOFB], visible: no

<7> [134.202375] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:163:cursor A] fb: [NOFB], visible: no

<7> [134.202737] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A

<7> [134.220283] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC2

<7> [134.220489] i915 0000:03:00.0: [drm:intel_dpll_disable [i915]] disable DPLL 2 (active 0x1, on? 1) for [CRTC:169:pipe A]

<7> [134.220690] i915 0000:03:00.0: [drm:intel_dpll_disable [i915]] disabling DPLL 2

<7> [134.220880] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:585:DDI A/PHY A]

<7> [134.221047] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:587:DP-MST A]

<7> [134.221222] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:588:DP-MST B]

<7> [134.221387] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:589:DP-MST C]

<7> [134.221552] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:590:DP-MST D]

<7> [134.221717] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:604:DDI B/PHY B]

<7> [134.221881] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:608:DDI TC1/PHY C]

<7> [134.222045] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:610:DP-MST A]

<7> [134.222252] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:611:DP-MST B]

<7> [134.222417] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:612:DP-MST C]

<7> [134.222581] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:613:DP-MST D]

<7> [134.222745] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:620:DDI TC2/PHY D]

<7> [134.222930] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:622:DP-MST A]

<7> [134.223133] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:623:DP-MST B]

<7> [134.223299] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:624:DP-MST C]

<7> [134.223464] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:625:DP-MST D]

<7> [134.223628] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:629:HDMI-A-4]

<7> [134.223910] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1

<7> [134.224178] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_3

<7> [134.224382] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2

<7> [134.224586] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:169:pipe A]

<7> [134.225222] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:307:pipe B]

<7> [134.225412] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:445:pipe C]

<7> [134.225586] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:583:pipe D]

<7> [134.225762] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:307:pipe B]

<7> [134.225798] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:629:HDMI-A-4]

<7> [134.225873] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CONNECTOR:629:HDMI-A-4] Limiting display bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)

<7> [134.226050] i915 0000:03:00.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)

<7> [134.226254] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:307:pipe B] hw max bpp: 24, pipe bpp: 24, dithering: 0

<7> [134.226425] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:620:DDI TC2/PHY D] [CRTC:307:pipe B]

<7> [134.226585] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.enable (expected no, found yes)

<7> [134.226755] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.active (expected no, found yes)

<7> [134.226924] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)

<7> [134.227131] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in lane_count (expected 0, found 4)

<7> [134.227299] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)

<7> [134.227469] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)

<7> [134.227637] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)

<7> [134.227806] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)

<7> [134.227974] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)

<7> [134.228186] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)

<7> [134.228355] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)

<7> [134.228523] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)

<7> [134.228691] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)

<7> [134.228860] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)

<7> [134.229028] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)

<7> [134.229235] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)

<7> [134.229404] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)

<7> [134.229573] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)

<7> [134.229740] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)

<7> [134.229908] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)

<7> [134.230103] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)

<7> [134.230286] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)

<7> [134.230454] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)

<7> [134.230622] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)

<7> [134.230790] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)

<7> [134.230959] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)

<7> [134.231165] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)

<7> [134.231334] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)

<7> [134.231503] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)

<7> [134.231671] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)

<7> [134.231840] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)

<7> [134.232009] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)

<7> [134.232218] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)

<7> [134.232388] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 24)

<7> [134.232556] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)

<7> [134.232725] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)

<7> [134.232894] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:307:pipe B] fastset requirement not met in port_clock (expected 0, found 148500)

<7> [134.233068] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:307:pipe B] fastset requirement not met, forcing full modeset

<7> [134.233299] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no

<7> [134.233463] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:307:pipe B] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x2

<7> [134.233667] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:171:plane 1B] ddb ( 0 - 0) -> ( 0 - 2012), size 0 -> 2012

<7> [134.233830] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:301:cursor B] ddb ( 0 - 0) -> (2012 - 2048), size 0 -> 36

<7> [134.233991] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:171:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm

<7> [134.234191] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:171:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 5, 5, 5, 8, 8, 9, 10, 0, 0, 0

<7> [134.234354] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:171:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 81, 81, 81, 129, 129, 145, 161, 30, 0, 0

<7> [134.234517] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:171:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 91, 91, 91, 143, 143, 161, 179, 31, 0, 0

<7> [134.234697] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:307:pipe B] data rate 594000 num active planes 1

<7> [134.234865] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 34000 required 594

<7> [134.235031] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1

<7> [134.235321] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:307:pipe B] min cdclk: 0 kHz -> 74250 kHz

<7> [134.235508] i915 0000:03:00.0: [drm:intel_find_dpll [i915]] [CRTC:307:pipe B] allocated DPLL 2

<7> [134.235677] i915 0000:03:00.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:307:pipe B] reserving DPLL 2

<7> [134.235847] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:307:pipe B] enable: yes [modeset]

<7> [134.236016] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB

<7> [134.236223] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 24, dithering: 0

<7> [134.236391] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>

<7> [134.236559] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0

<7> [134.236725] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0

<7> [134.236892] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0

<7> [134.237064] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0

<7> [134.237270] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2

<7> [134.237436] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0

<7> [134.237603] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 42, guardband: 44 vsync start: 0, vsync end: 0

<7> [134.237771] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125

<7> [134.237938] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [134.238146] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [134.238314] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [134.238483] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5

<7> [134.238651] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [134.238819] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 74250

<7> [134.238987] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0

<7> [134.239192] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0

<7> [134.239361] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no

<7> [134.239529] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0

<7> [134.239696] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1001d0, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0

<7> [134.239864] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0

<7> [134.240031] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries

<7> [134.240236] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000

<7> [134.240404] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [134.240570] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [134.240737] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [134.240904] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000

<7> [134.241093] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000

<7> [134.241274] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [134.241441] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [134.241608] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [134.241775] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000

<7> [134.241941] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0

<7> [134.242150] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:171:plane 1B] fb: [FB:635] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes

<7> [134.242319] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0

<7> [134.242487] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0

<7> [134.242653] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:201:plane 2B] fb: [NOFB], visible: no

<7> [134.242820] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:231:plane 3B] fb: [NOFB], visible: no

<7> [134.242987] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:261:plane 4B] fb: [NOFB], visible: no

<7> [134.243194] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 5B] fb: [NOFB], visible: no

<7> [134.243362] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:281:plane 6B] fb: [NOFB], visible: no

<7> [134.243529] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:291:plane 7B] fb: [NOFB], visible: no

<7> [134.243696] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:cursor B] fb: [NOFB], visible: no

<7> [134.244145] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2

<7> [134.244326] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_3

<7> [134.244537] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:585:DDI A/PHY A]

<7> [134.244702] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:587:DP-MST A]

<7> [134.244868] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:588:DP-MST B]

<7> [134.245032] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:589:DP-MST C]

<7> [134.245236] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:590:DP-MST D]

<7> [134.245402] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:604:DDI B/PHY B]

<7> [134.245567] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:608:DDI TC1/PHY C]

<7> [134.245732] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:610:DP-MST A]

<7> [134.245896] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:611:DP-MST B]

<7> [134.246067] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:612:DP-MST C]

<7> [134.246267] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:613:DP-MST D]

<7> [134.246432] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:620:DDI TC2/PHY D]

<7> [134.246596] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:622:DP-MST A]

<7> [134.246761] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:623:DP-MST B]

<7> [134.246927] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:624:DP-MST C]

<7> [134.247139] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:625:DP-MST D]

<7> [134.247381] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3

<7> [134.247596] i915 0000:03:00.0: [drm:intel_dpll_enable [i915]] enable DPLL 2 (active 0x2, on? 0) for [CRTC:307:pipe B]

<7> [134.247765] i915 0000:03:00.0: [drm:intel_dpll_enable [i915]] enabling DPLL 2

<7> [134.247986] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC2

<7> [134.248270] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe B

<7> [134.266380] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:629:HDMI-A-4]

<7> [134.266667] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:307:pipe B]

<6> [137.095518] [IGT] kms_flip: finished subtest B-HDMI-A4, FAIL

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