igt@kms_flip@flip-vs-expired-vblank-interruptible@a-hdmi-a2 on shard-rkl@CI_DRM

Detail	Value
Duration	3.76 seconds
Hostname	shard-rkl-7
Igt-Version	IGT-Version: 2.4-g4568b2c14 (x86_64) (Linux: 7.1.0-rc1-CI_DRM_18372-g1c60044e7e22+ x86_64)
Out	Using IGT_SRANDOM=1777339211 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: flip-vs-expired-vblank-interruptible Starting dynamic subtest: A-HDMI-A2 1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A2: FAIL (3.761s)
Err	Starting subtest: flip-vs-expired-vblank-interruptible Starting dynamic subtest: A-HDMI-A2 (kms_flip:2213) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2213) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2213) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-HDMI-A2 failed. ** DEBUG (kms_flip:2213) DEBUG: Vblank took 30us (kms_flip:2213) DEBUG: name = flip last_ts = 204.777679 last_received_ts = 204.777100 last_seq = 7984 current_ts = 204.796661 current_received_ts = 204.796143 current_seq = 7985 count = 64 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 204.796661 last_received_ts = 204.796143 last_seq = 7985 current_ts = 204.815628 current_received_ts = 204.815048 current_seq = 7986 count = 65 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 204.815628 last_received_ts = 204.815048 last_seq = 7986 current_ts = 204.834595 current_received_ts = 204.833984 current_seq = 7987 count = 66 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 37us (kms_flip:2213) DEBUG: name = flip last_ts = 204.834595 last_received_ts = 204.833984 last_seq = 7987 current_ts = 204.853577 current_received_ts = 204.852982 current_seq = 7988 count = 67 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 204.853577 last_received_ts = 204.852982 last_seq = 7988 current_ts = 204.872559 current_received_ts = 204.871887 current_seq = 7989 count = 68 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 204.872559 last_received_ts = 204.871887 last_seq = 7989 current_ts = 204.891525 current_received_ts = 204.890945 current_seq = 7990 count = 69 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 45us (kms_flip:2213) DEBUG: name = flip last_ts = 204.891525 last_received_ts = 204.890945 last_seq = 7990 current_ts = 204.910507 current_received_ts = 204.909897 current_seq = 7991 count = 70 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 204.910507 last_received_ts = 204.909897 last_seq = 7991 current_ts = 204.929474 current_received_ts = 204.928879 current_seq = 7992 count = 71 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 204.929474 last_received_ts = 204.928879 last_seq = 7992 current_ts = 204.948441 current_received_ts = 204.947876 current_seq = 7993 count = 72 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 28us (kms_flip:2213) DEBUG: name = flip last_ts = 204.948441 last_received_ts = 204.947876 last_seq = 7993 current_ts = 204.967422 current_received_ts = 204.966827 current_seq = 7994 count = 73 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 30us (kms_flip:2213) DEBUG: name = flip last_ts = 204.967422 last_received_ts = 204.966827 last_seq = 7994 current_ts = 204.986404 current_received_ts = 204.985733 current_seq = 7995 count = 74 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 204.986404 last_received_ts = 204.985733 last_seq = 7995 current_ts = 205.005356 current_received_ts = 205.004822 current_seq = 7996 count = 75 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.005356 last_received_ts = 205.004822 last_seq = 7996 current_ts = 205.024353 current_received_ts = 205.023788 current_seq = 7997 count = 76 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.024353 last_received_ts = 205.023788 last_seq = 7997 current_ts = 205.043320 current_received_ts = 205.042725 current_seq = 7998 count = 77 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.043320 last_received_ts = 205.042725 last_seq = 7998 current_ts = 205.062302 current_received_ts = 205.061691 current_seq = 7999 count = 78 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.062302 last_received_ts = 205.061691 last_seq = 7999 current_ts = 205.081268 current_received_ts = 205.080719 current_seq = 8000 count = 79 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.081268 last_received_ts = 205.080719 last_seq = 8000 current_ts = 205.100250 current_received_ts = 205.099579 current_seq = 8001 count = 80 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 41us (kms_flip:2213) DEBUG: name = flip last_ts = 205.100250 last_received_ts = 205.099579 last_seq = 8001 current_ts = 205.119217 current_received_ts = 205.118576 current_seq = 8002 count = 81 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 50us (kms_flip:2213) DEBUG: name = flip last_ts = 205.119217 last_received_ts = 205.118576 last_seq = 8002 current_ts = 205.138184 current_received_ts = 205.137604 current_seq = 8003 count = 82 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 205.138184 last_received_ts = 205.137604 last_seq = 8003 current_ts = 205.157166 current_received_ts = 205.156570 current_seq = 8004 count = 83 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 205.157166 last_received_ts = 205.156570 last_seq = 8004 current_ts = 205.176147 current_received_ts = 205.175537 current_seq = 8005 count = 84 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.176147 last_received_ts = 205.175537 last_seq = 8005 current_ts = 205.195114 current_received_ts = 205.194519 current_seq = 8006 count = 85 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.195114 last_received_ts = 205.194519 last_seq = 8006 current_ts = 205.214081 current_received_ts = 205.213455 current_seq = 8007 count = 86 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 40us (kms_flip:2213) DEBUG: name = flip last_ts = 205.214081 last_received_ts = 205.213455 last_seq = 8007 current_ts = 205.233063 current_received_ts = 205.232407 current_seq = 8008 count = 87 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.233063 last_received_ts = 205.232407 last_seq = 8008 current_ts = 205.252045 current_received_ts = 205.251389 current_seq = 8009 count = 88 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.252045 last_received_ts = 205.251389 last_seq = 8009 current_ts = 205.270996 current_received_ts = 205.270508 current_seq = 8010 count = 89 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.270996 last_received_ts = 205.270508 last_seq = 8010 current_ts = 205.289993 current_received_ts = 205.289383 current_seq = 8011 count = 90 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 205.289993 last_received_ts = 205.289383 last_seq = 8011 current_ts = 205.308960 current_received_ts = 205.308350 current_seq = 8012 count = 91 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.308960 last_received_ts = 205.308350 last_seq = 8012 current_ts = 205.327927 current_received_ts = 205.327301 current_seq = 8013 count = 92 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 40us (kms_flip:2213) DEBUG: name = flip last_ts = 205.327927 last_received_ts = 205.327301 last_seq = 8013 current_ts = 205.346909 current_received_ts = 205.346313 current_seq = 8014 count = 93 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 27us (kms_flip:2213) DEBUG: name = flip last_ts = 205.346909 last_received_ts = 205.346313 last_seq = 8014 current_ts = 205.365891 current_received_ts = 205.365280 current_seq = 8015 count = 94 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.365891 last_received_ts = 205.365280 last_seq = 8015 current_ts = 205.384842 current_received_ts = 205.384232 current_seq = 8016 count = 95 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 30us (kms_flip:2213) DEBUG: name = flip last_ts = 205.384842 last_received_ts = 205.384232 last_seq = 8016 current_ts = 205.403824 current_received_ts = 205.403183 current_seq = 8017 count = 96 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 205.403824 last_received_ts = 205.403183 last_seq = 8017 current_ts = 205.422806 current_received_ts = 205.422180 current_seq = 8018 count = 97 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 43us (kms_flip:2213) DEBUG: name = flip last_ts = 205.422806 last_received_ts = 205.422180 last_seq = 8018 current_ts = 205.441772 current_received_ts = 205.441177 current_seq = 8019 count = 98 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.441772 last_received_ts = 205.441177 last_seq = 8019 current_ts = 205.460739 current_received_ts = 205.460236 current_seq = 8020 count = 99 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.460739 last_received_ts = 205.460236 last_seq = 8020 current_ts = 205.479736 current_received_ts = 205.479111 current_seq = 8021 count = 100 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 205.479736 last_received_ts = 205.479111 last_seq = 8021 current_ts = 205.498703 current_received_ts = 205.498123 current_seq = 8022 count = 101 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 27us (kms_flip:2213) DEBUG: name = flip last_ts = 205.498703 last_received_ts = 205.498123 last_seq = 8022 current_ts = 205.517670 current_received_ts = 205.517212 current_seq = 8023 count = 102 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.517670 last_received_ts = 205.517212 last_seq = 8023 current_ts = 205.536636 current_received_ts = 205.536041 current_seq = 8024 count = 103 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.536636 last_received_ts = 205.536041 last_seq = 8024 current_ts = 205.555618 current_received_ts = 205.554962 current_seq = 8025 count = 104 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 63us (kms_flip:2213) DEBUG: name = flip last_ts = 205.555618 last_received_ts = 205.554962 last_seq = 8025 current_ts = 205.574600 current_received_ts = 205.574081 current_seq = 8026 count = 105 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 205.574600 last_received_ts = 205.574081 last_seq = 8026 current_ts = 205.593582 current_received_ts = 205.592987 current_seq = 8027 count = 106 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 205.593582 last_received_ts = 205.592987 last_seq = 8027 current_ts = 205.612549 current_received_ts = 205.611938 current_seq = 8028 count = 107 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 52us (kms_flip:2213) DEBUG: name = flip last_ts = 205.612549 last_received_ts = 205.611938 last_seq = 8028 current_ts = 205.631516 current_received_ts = 205.630920 current_seq = 8029 count = 108 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.631516 last_received_ts = 205.630920 last_seq = 8029 current_ts = 205.650482 current_received_ts = 205.649872 current_seq = 8030 count = 109 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.650482 last_received_ts = 205.649872 last_seq = 8030 current_ts = 205.669479 current_received_ts = 205.668808 current_seq = 8031 count = 110 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.669479 last_received_ts = 205.668808 last_seq = 8031 current_ts = 205.688446 current_received_ts = 205.687820 current_seq = 8032 count = 111 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.688446 last_received_ts = 205.687820 last_seq = 8032 current_ts = 205.707413 current_received_ts = 205.706924 current_seq = 8033 count = 112 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.707413 last_received_ts = 205.706924 last_seq = 8033 current_ts = 205.726395 current_received_ts = 205.725784 current_seq = 8034 count = 113 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.726395 last_received_ts = 205.725784 last_seq = 8034 current_ts = 205.745377 current_received_ts = 205.744934 current_seq = 8035 count = 114 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 205.745377 last_received_ts = 205.744934 last_seq = 8035 current_ts = 205.764343 current_received_ts = 205.763718 current_seq = 8036 count = 115 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 205.764343 last_received_ts = 205.763718 last_seq = 8036 current_ts = 205.783310 current_received_ts = 205.782715 current_seq = 8037 count = 116 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 205.783310 last_received_ts = 205.782715 last_seq = 8037 current_ts = 205.802292 current_received_ts = 205.801712 current_seq = 8038 count = 117 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 205.802292 last_received_ts = 205.801712 last_seq = 8038 current_ts = 205.821259 current_received_ts = 205.820663 current_seq = 8039 count = 118 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.821259 last_received_ts = 205.820663 last_seq = 8039 current_ts = 205.840225 current_received_ts = 205.839615 current_seq = 8040 count = 119 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 28us (kms_flip:2213) DEBUG: name = flip last_ts = 205.840225 last_received_ts = 205.839615 last_seq = 8040 current_ts = 205.859207 current_received_ts = 205.858658 current_seq = 8041 count = 120 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 30us (kms_flip:2213) DEBUG: name = flip last_ts = 205.859207 last_received_ts = 205.858658 last_seq = 8041 current_ts = 205.878174 current_received_ts = 205.877548 current_seq = 8042 count = 121 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 205.878174 last_received_ts = 205.877548 last_seq = 8042 current_ts = 205.897156 current_received_ts = 205.896530 current_seq = 8043 count = 122 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 205.897156 last_received_ts = 205.896530 last_seq = 8043 current_ts = 205.916122 current_received_ts = 205.915543 current_seq = 8044 count = 123 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 28us (kms_flip:2213) DEBUG: name = flip last_ts = 205.916122 last_received_ts = 205.915543 last_seq = 8044 current_ts = 205.935104 current_received_ts = 205.934494 current_seq = 8045 count = 124 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.935104 last_received_ts = 205.934494 last_seq = 8045 current_ts = 205.954086 current_received_ts = 205.953430 current_seq = 8046 count = 125 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 205.954086 last_received_ts = 205.953430 last_seq = 8046 current_ts = 205.973038 current_received_ts = 205.972565 current_seq = 8047 count = 126 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.973038 last_received_ts = 205.972565 last_seq = 8047 current_ts = 205.992035 current_received_ts = 205.991409 current_seq = 8048 count = 127 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 205.992035 last_received_ts = 205.991409 last_seq = 8048 current_ts = 206.011002 current_received_ts = 206.010345 current_seq = 8049 count = 128 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 30us (kms_flip:2213) DEBUG: name = flip last_ts = 206.011002 last_received_ts = 206.010345 last_seq = 8049 current_ts = 206.029984 current_received_ts = 206.029373 current_seq = 8050 count = 129 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.029984 last_received_ts = 206.029373 last_seq = 8050 current_ts = 206.048950 current_received_ts = 206.048325 current_seq = 8051 count = 130 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 28us (kms_flip:2213) DEBUG: name = flip last_ts = 206.048950 last_received_ts = 206.048325 last_seq = 8051 current_ts = 206.067932 current_received_ts = 206.067337 current_seq = 8052 count = 131 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 206.067932 last_received_ts = 206.067337 last_seq = 8052 current_ts = 206.086899 current_received_ts = 206.086273 current_seq = 8053 count = 132 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.086899 last_received_ts = 206.086273 last_seq = 8053 current_ts = 206.105881 current_received_ts = 206.105331 current_seq = 8054 count = 133 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.105881 last_received_ts = 206.105331 last_seq = 8054 current_ts = 206.124832 current_received_ts = 206.124207 current_seq = 8055 count = 134 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 27us (kms_flip:2213) DEBUG: name = flip last_ts = 206.124832 last_received_ts = 206.124207 last_seq = 8055 current_ts = 206.143814 current_received_ts = 206.143234 current_seq = 8056 count = 135 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.143814 last_received_ts = 206.143234 last_seq = 8056 current_ts = 206.162796 current_received_ts = 206.162247 current_seq = 8057 count = 136 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.162796 last_received_ts = 206.162247 last_seq = 8057 current_ts = 206.181763 current_received_ts = 206.181244 current_seq = 8058 count = 137 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.181763 last_received_ts = 206.181244 last_seq = 8058 current_ts = 206.200745 current_received_ts = 206.200180 current_seq = 8059 count = 138 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 27us (kms_flip:2213) DEBUG: name = flip last_ts = 206.200745 last_received_ts = 206.200180 last_seq = 8059 current_ts = 206.219711 current_received_ts = 206.219116 current_seq = 8060 count = 139 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 206.219711 last_received_ts = 206.219116 last_seq = 8060 current_ts = 206.238678 current_received_ts = 206.238068 current_seq = 8061 count = 140 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.238678 last_received_ts = 206.238068 last_seq = 8061 current_ts = 206.257675 current_received_ts = 206.257721 current_seq = 8062 count = 141 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.257675 last_received_ts = 206.257721 last_seq = 8062 current_ts = 206.276642 current_received_ts = 206.276154 current_seq = 8063 count = 142 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.276642 last_received_ts = 206.276154 last_seq = 8063 current_ts = 206.295609 current_received_ts = 206.295044 current_seq = 8064 count = 143 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 206.295609 last_received_ts = 206.295044 last_seq = 8064 current_ts = 206.314590 current_received_ts = 206.314163 current_seq = 8065 count = 144 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.314590 last_received_ts = 206.314163 last_seq = 8065 current_ts = 206.333572 current_received_ts = 206.332977 current_seq = 8066 count = 145 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 206.333572 last_received_ts = 206.332977 last_seq = 8066 current_ts = 206.352539 current_received_ts = 206.351913 current_seq = 8067 count = 146 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 206.352539 last_received_ts = 206.351913 last_seq = 8067 current_ts = 206.371506 current_received_ts = 206.370834 current_seq = 8068 count = 147 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 27us (kms_flip:2213) DEBUG: name = flip last_ts = 206.371506 last_received_ts = 206.370834 last_seq = 8068 current_ts = 206.390472 current_received_ts = 206.389893 current_seq = 8069 count = 148 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 66us (kms_flip:2213) DEBUG: name = flip last_ts = 206.390472 last_received_ts = 206.389893 last_seq = 8069 current_ts = 206.409470 current_received_ts = 206.408875 current_seq = 8070 count = 149 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.409470 last_received_ts = 206.408875 last_seq = 8070 current_ts = 206.428421 current_received_ts = 206.427826 current_seq = 8071 count = 150 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 27us (kms_flip:2213) DEBUG: name = flip last_ts = 206.428421 last_received_ts = 206.427826 last_seq = 8071 current_ts = 206.447403 current_received_ts = 206.446854 current_seq = 8072 count = 151 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 206.447403 last_received_ts = 206.446854 last_seq = 8072 current_ts = 206.466385 current_received_ts = 206.465790 current_seq = 8073 count = 152 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.466385 last_received_ts = 206.465790 last_seq = 8073 current_ts = 206.485367 current_received_ts = 206.484695 current_seq = 8074 count = 153 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.485367 last_received_ts = 206.484695 last_seq = 8074 current_ts = 206.504318 current_received_ts = 206.503738 current_seq = 8075 count = 154 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 206.504318 last_received_ts = 206.503738 last_seq = 8075 current_ts = 206.523300 current_received_ts = 206.522736 current_seq = 8076 count = 155 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 29us (kms_flip:2213) DEBUG: name = flip last_ts = 206.523300 last_received_ts = 206.522736 last_seq = 8076 current_ts = 206.542282 current_received_ts = 206.541687 current_seq = 8077 count = 156 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 206.542282 last_received_ts = 206.541687 last_seq = 8077 current_ts = 206.561249 current_received_ts = 206.560669 current_seq = 8078 count = 157 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.561249 last_received_ts = 206.560669 last_seq = 8078 current_ts = 206.580231 current_received_ts = 206.579681 current_seq = 8079 count = 158 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.580231 last_received_ts = 206.579681 last_seq = 8079 current_ts = 206.599197 current_received_ts = 206.598587 current_seq = 8080 count = 159 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 28us (kms_flip:2213) DEBUG: name = flip last_ts = 206.599197 last_received_ts = 206.598587 last_seq = 8080 current_ts = 206.618179 current_received_ts = 206.617508 current_seq = 8081 count = 160 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.618179 last_received_ts = 206.617508 last_seq = 8081 current_ts = 206.637146 current_received_ts = 206.636566 current_seq = 8082 count = 161 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.637146 last_received_ts = 206.636566 last_seq = 8082 current_ts = 206.656113 current_received_ts = 206.655579 current_seq = 8083 count = 162 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.656113 last_received_ts = 206.655579 last_seq = 8083 current_ts = 206.675095 current_received_ts = 206.674515 current_seq = 8084 count = 163 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 206.675095 last_received_ts = 206.674515 last_seq = 8084 current_ts = 206.694077 current_received_ts = 206.693481 current_seq = 8085 count = 164 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.694077 last_received_ts = 206.693481 last_seq = 8085 current_ts = 206.713043 current_received_ts = 206.712387 current_seq = 8086 count = 165 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.713043 last_received_ts = 206.712387 last_seq = 8086 current_ts = 206.732025 current_received_ts = 206.731461 current_seq = 8087 count = 166 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.732025 last_received_ts = 206.731461 last_seq = 8087 current_ts = 206.750992 current_received_ts = 206.750366 current_seq = 8088 count = 167 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 27us (kms_flip:2213) DEBUG: name = flip last_ts = 206.750992 last_received_ts = 206.750366 last_seq = 8088 current_ts = 206.769974 current_received_ts = 206.769348 current_seq = 8089 count = 168 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.769974 last_received_ts = 206.769348 last_seq = 8089 current_ts = 206.788940 current_received_ts = 206.788315 current_seq = 8090 count = 169 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 31us (kms_flip:2213) DEBUG: name = flip last_ts = 206.788940 last_received_ts = 206.788315 last_seq = 8090 current_ts = 206.807907 current_received_ts = 206.807281 current_seq = 8091 count = 170 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 28us (kms_flip:2213) DEBUG: name = flip last_ts = 206.807907 last_received_ts = 206.807281 last_seq = 8091 current_ts = 206.826889 current_received_ts = 206.826355 current_seq = 8092 count = 171 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 32us (kms_flip:2213) DEBUG: name = flip last_ts = 206.826889 last_received_ts = 206.826355 last_seq = 8092 current_ts = 206.845856 current_received_ts = 206.845261 current_seq = 8093 count = 172 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.845856 last_received_ts = 206.845261 last_seq = 8093 current_ts = 206.864838 current_received_ts = 206.864258 current_seq = 8094 count = 173 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.864838 last_received_ts = 206.864258 last_seq = 8094 current_ts = 206.883804 current_received_ts = 206.883240 current_seq = 8095 count = 174 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 206.883804 last_received_ts = 206.883240 last_seq = 8095 current_ts = 206.902786 current_received_ts = 206.902145 current_seq = 8096 count = 175 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 206.902786 last_received_ts = 206.902145 last_seq = 8096 current_ts = 206.921753 current_received_ts = 206.921143 current_seq = 8097 count = 176 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.921753 last_received_ts = 206.921143 last_seq = 8097 current_ts = 206.940735 current_received_ts = 206.940155 current_seq = 8098 count = 177 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.940735 last_received_ts = 206.940155 last_seq = 8098 current_ts = 206.959702 current_received_ts = 206.959183 current_seq = 8099 count = 178 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.959702 last_received_ts = 206.959183 last_seq = 8099 current_ts = 206.978683 current_received_ts = 206.978104 current_seq = 8100 count = 179 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 206.978683 last_received_ts = 206.978104 last_seq = 8100 current_ts = 206.997650 current_received_ts = 206.997177 current_seq = 8101 count = 180 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 34us (kms_flip:2213) DEBUG: name = flip last_ts = 206.997650 last_received_ts = 206.997177 last_seq = 8101 current_ts = 207.016617 current_received_ts = 207.016037 current_seq = 8102 count = 181 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 33us (kms_flip:2213) DEBUG: name = flip last_ts = 207.016617 last_received_ts = 207.016037 last_seq = 8102 current_ts = 207.035614 current_received_ts = 207.034958 current_seq = 8103 count = 182 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 59us (kms_flip:2213) DEBUG: name = flip last_ts = 207.035614 last_received_ts = 207.034958 last_seq = 8103 current_ts = 207.054581 current_received_ts = 207.054077 current_seq = 8104 count = 183 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 35us (kms_flip:2213) DEBUG: name = flip last_ts = 207.054581 last_received_ts = 207.054077 last_seq = 8104 current_ts = 207.073547 current_received_ts = 207.072968 current_seq = 8105 count = 184 seq_step = 1 (kms_flip:2213) DEBUG: Vblank took 828us (kms_flip:2213) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:2213) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2213) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2213) igt_core-INFO: Stack trace: (kms_flip:2213) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2213) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:2213) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:2213) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() (kms_flip:2213) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:2213) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2213) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2213) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A2: FAIL (3.761s)
Dmesg	<6> [203.162923] Console: switching to colour dummy device 80x25 <6> [203.163321] [IGT] kms_flip: executing <7> [203.165758] i915 0000:00:02.0: [drm:i915_gem_open [i915]] <7> [203.166309] i915 0000:00:02.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x000001dc [0x000001dc] <7> [203.166516] i915 0000:00:02.0: [drm:i915_gem_open [i915]] <7> [203.170568] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:390:HDMI-A-1] <7> [203.170575] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:390:HDMI-A-1] <7> [203.174779] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:390:HDMI-A-1] disconnected <7> [203.175167] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:404:DP-1] <7> [203.175172] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:404:DP-1] <7> [203.179367] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:404:DP-1] disconnected <7> [203.179611] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:HDMI-A-3] <7> [203.179615] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:412:HDMI-A-3] <7> [203.183821] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:HDMI-A-3] disconnected <7> [203.184124] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:390:HDMI-A-1] <7> [203.184128] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:390:HDMI-A-1] <7> [203.188307] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:390:HDMI-A-1] disconnected <7> [203.188318] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:HDMI-A-2] <7> [203.188322] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:400:HDMI-A-2] <7> [203.214075] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:400:HDMI-A-2] Supported Monitor Refresh rate range is 0 Hz - 0 Hz <7> [203.214083] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:400:HDMI-A-2] Assigning EDID-1.4 digital sink color depth as 8 bpc. <7> [203.214086] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:400:HDMI-A-2] ELD monitor fitHeadless4k <7> [203.214088] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:400:HDMI-A-2] ELD size 36, SAD count 0 <7> [203.214296] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK for addr: 0040 w(1) <7> [203.214420] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK on first message, retry <7> [203.214725] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK for addr: 0040 w(1) <7> [203.214848] i915 0000:00:02.0: [drm:drm_dp_dual_mode_detect [drm_display_helper]] DP dual mode HDMI ID: (err -6) <7> [203.215219] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1366x768": 216 268000 1366 1414 1446 1526 768 771 777 814 0x40 0x6 (CLOCK_HIGH) <7> [203.215225] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74250 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE) <7> [203.215230] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74176 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE) <7> [203.215236] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:HDMI-A-2] probed modes: <7> [203.215239] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 <7> [203.215243] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "4088x2304": 10 108000 4088 4152 4280 4536 2304 2305 2308 2340 0x40 0x5 <7> [203.215246] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "3840x2160": 15 128430 3840 3889 3921 4000 2160 2163 2169 2195 0x40 0xa <7> [203.215250] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 11 60000 2880 2888 2984 3040 1800 1802 1820 1845 0x40 0xa <7> [203.215253] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1600": 13 60000 2560 2568 2664 2720 1600 1602 1620 1645 0x40 0xa <7> [203.215256] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1440": 15 60000 2560 2568 2664 2720 1440 1442 1460 1485 0x40 0xa <7> [203.215259] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2048x1536": 17 60000 2048 2056 2152 2208 1536 1538 1556 1581 0x40 0xa <7> [203.215263] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1600x1200": 60 162000 1600 1664 1856 2160 1200 1201 1204 1250 0x40 0x5 <7> [203.215266] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1680x1050": 60 146250 1680 1784 1960 2240 1050 1053 1059 1089 0x40 0x6 <7> [203.215269] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1600x900": 60 108000 1600 1624 1704 1800 900 901 904 1000 0x40 0x5 <7> [203.215272] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x1024": 75 135000 1280 1296 1440 1688 1024 1025 1028 1066 0x40 0x5 <7> [203.215276] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1360x768": 60 84963 1366 1431 1567 1776 768 771 781 798 0x0 0x6 <7> [203.215279] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1360x768": 20 25190 1360 1368 1464 1520 768 770 788 813 0x40 0xa <7> [203.215282] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x800": 60 83500 1280 1352 1480 1680 800 803 809 831 0x40 0x6 <7> [203.215285] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1152x864": 75 108000 1152 1216 1344 1600 864 865 868 900 0x40 0x5 <7> [203.215289] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5 <7> [203.215292] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5 <7> [203.215295] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74176 1280 1390 1430 1650 720 725 730 750 0x40 0x5 <7> [203.215298] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 75 78750 1024 1040 1136 1312 768 769 772 800 0x40 0x5 <7> [203.215301] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 60 65000 1024 1048 1184 1344 768 771 777 806 0x40 0xa <7> [203.215305] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1440x480": 60 54054 1440 1472 1596 1716 480 489 495 525 0x40 0xa <7> [203.215308] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1440x480": 60 54000 1440 1472 1596 1716 480 489 495 525 0x40 0xa <7> [203.215311] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x576": 60 46560 1024 1064 1160 1296 576 579 584 599 0x0 0x6 <7> [203.215314] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "832x624": 75 57284 832 864 928 1152 624 625 628 667 0x40 0xa <7> [203.215317] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 75 49500 800 816 896 1056 600 601 604 625 0x40 0x5 <7> [203.215320] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 60 40000 800 840 968 1056 600 601 605 628 0x40 0x5 <7> [203.215323] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 75 31500 640 656 720 840 480 481 484 500 0x40 0xa <7> [203.215327] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25200 640 656 752 800 480 490 492 525 0x40 0xa <7> [203.215330] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa <7> [203.215333] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa <7> [203.215336] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "720x400": 70 28320 720 738 846 900 400 412 414 449 0x40 0x6 <7> [203.215359] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:404:DP-1] <7> [203.215363] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:404:DP-1] <7> [203.219531] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:404:DP-1] disconnected <7> [203.219544] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:HDMI-A-3] <7> [203.219547] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:412:HDMI-A-3] <7> [203.223735] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:HDMI-A-3] disconnected <6> [203.227920] [IGT] kms_flip: starting subtest flip-vs-expired-vblank-interruptible <6> [203.229975] [IGT] kms_flip: starting dynamic subtest A-HDMI-A2 <7> [203.230320] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:417] <7> [203.230413] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:419] <7> [203.273846] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [203.273927] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [203.274131] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [203.274270] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [203.274406] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [203.274541] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [203.274677] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [203.274812] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [203.274946] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2360, found 0) <7> [203.275096] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [203.275229] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2360, found 0) <7> [203.275363] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [203.275497] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2096, found 0) <7> [203.275631] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [203.275765] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [203.275898] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [203.276042] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [203.276175] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [203.276307] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [203.276457] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [203.276594] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2360, found 0) <7> [203.276729] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [203.276863] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2360, found 0) <7> [203.277007] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [203.277140] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2096, found 0) <7> [203.277273] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [203.277404] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [203.277537] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [203.277669] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [203.277802] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [203.277934] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [203.278115] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [203.278247] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [203.278380] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [203.278513] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [203.278645] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 139929, found 0) <7> [203.278777] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 139929, found 0) <7> [203.278909] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 139929, found 0) <7> [203.279053] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [203.279186] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:151:pipe A] releasing DPLL 0 <7> [203.279346] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no <7> [203.279478] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [203.279630] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0 <7> [203.279761] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0 <7> [203.279892] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm <7> [203.280033] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [203.280165] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [203.280295] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [203.280438] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 0 num active planes 0 <7> [203.280574] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0 <7> [203.280709] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1 <7> [203.280861] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 69965 kHz -> 0 kHz <7> [203.281022] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 26237 kHz -> 0 kHz <7> [203.281160] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: no [modeset] <7> [203.281296] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [NOFB], visible: no <7> [203.281429] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [203.281563] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [203.281696] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [203.281829] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [203.281970] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [203.294228] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A <7> [203.313096] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC1 <7> [203.313614] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A] <7> [203.314172] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0 <7> [203.314644] i915 0000:00:02.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:35:plane 1A] <7> [203.315139] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B] <7> [203.315583] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C] <7> [203.316085] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D] <7> [203.316521] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A] <7> [203.316977] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B] <7> [203.317415] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C] <7> [203.317851] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:400:HDMI-A-2] <7> [203.318435] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1 <7> [203.318850] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3 <7> [203.319328] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A] <7> [203.320255] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B] <7> [203.320548] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C] <7> [203.320819] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [203.320865] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:400:HDMI-A-2] <7> [203.321017] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:400:HDMI-A-2] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36) <7> [203.321304] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24) <7> [203.321558] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0 <7> [203.321834] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:399:DDI TC1/PHY C] [CRTC:151:pipe A] <7> [203.322117] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [203.322394] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [203.322668] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [203.322940] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [203.323240] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [203.323507] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [203.323793] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [203.324055] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2360) <7> [203.324257] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [203.324458] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2360) <7> [203.324659] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [203.324860] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2096) <7> [203.325073] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [203.325276] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [203.325477] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [203.325678] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [203.325879] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [203.326096] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [203.326297] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [203.326497] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2360) <7> [203.326698] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [203.326898] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2360) <7> [203.327108] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [203.327254] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2096) <7> [203.327399] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [203.327546] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [203.327692] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [203.327840] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [203.327997] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [203.328143] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [203.328290] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [203.328436] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [203.328583] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [203.328730] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [203.328877] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 139929) <7> [203.329033] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 139929) <7> [203.329180] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 139929) <7> [203.329327] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [203.329496] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no <7> [203.329644] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x1 <7> [203.329817] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016 <7> [203.329971] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32 <7> [203.330116] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,twm, swm, stwm <7> [203.330266] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 <7> [203.330395] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 <7> [203.330523] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 <7> [203.330662] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 559716 num active planes 1 <7> [203.330798] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560 <7> [203.330931] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1 <7> [203.331134] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 69965 kHz <7> [203.331279] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 8746 kHz <7> [203.331413] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:151:pipe A] allocated DPLL 0 <7> [203.331549] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:151:pipe A] reserving DPLL 0 <7> [203.331687] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: yes [modeset] <7> [203.331825] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [203.331967] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0 <7> [203.332100] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [203.332232] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [203.332363] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [203.332495] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [203.332625] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0 <7> [203.332756] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [203.332887] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [203.333026] i915 0000:00:02.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> [203.333158] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125 <7> [203.333288] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [203.333418] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 <7> [203.333549] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 <7> [203.333679] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [203.333810] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5 <7> [203.333941] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [203.334084] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0 <7> [203.334216] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 135, ips linetime: 0 <7> [203.334346] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [203.334476] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [203.334606] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [203.334736] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [203.334865] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [203.335003] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, 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> [203.335133] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [203.335263] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [203.335392] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [203.335523] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [203.335653] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [203.335782] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [203.335911] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [203.336052] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [203.336182] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [203.336311] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [203.336441] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [203.336570] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [203.336699] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:417] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [203.336830] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [203.336966] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [203.337096] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [203.337226] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [203.337355] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [203.337484] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [203.337614] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [203.338270] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3 <7> [203.338421] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:389:DDI B/PHY B] <7> [203.338557] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C] <7> [203.338691] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D] <7> [203.338825] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A] <7> [203.338967] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B] <7> [203.339101] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C] <7> [203.339271] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3 <7> [203.339495] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A] <7> [203.339633] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0 <7> [203.340054] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC1 <7> [203.340228] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [203.340616] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1 <7> [203.340755] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A] <7> [203.359747] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:400:HDMI-A-2] <7> [203.360062] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A] <6> [206.991315] [IGT] kms_flip: finished subtest A-HDMI-A2, FAIL

Detail

Value

Duration

3.76 seconds

Hostname

shard-rkl-7

Igt-Version

IGT-Version: 2.4-g4568b2c14 (x86_64) (Linux: 7.1.0-rc1-CI_DRM_18372-g1c60044e7e22+ x86_64)

Out

Using IGT_SRANDOM=1777339211 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: flip-vs-expired-vblank-interruptible
Starting dynamic subtest: A-HDMI-A2
  1920x1080: 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A2: FAIL (3.761s)

Err

Starting subtest: flip-vs-expired-vblank-interruptible
Starting dynamic subtest: A-HDMI-A2
(kms_flip:2213) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2213) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2213) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-HDMI-A2 failed.
**** DEBUG ****
(kms_flip:2213) DEBUG: Vblank took 30us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.777679
last_received_ts = 204.777100
last_seq = 7984
current_ts = 204.796661
current_received_ts = 204.796143
current_seq = 7985
count = 64
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.796661
last_received_ts = 204.796143
last_seq = 7985
current_ts = 204.815628
current_received_ts = 204.815048
current_seq = 7986
count = 65
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.815628
last_received_ts = 204.815048
last_seq = 7986
current_ts = 204.834595
current_received_ts = 204.833984
current_seq = 7987
count = 66
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 37us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.834595
last_received_ts = 204.833984
last_seq = 7987
current_ts = 204.853577
current_received_ts = 204.852982
current_seq = 7988
count = 67
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.853577
last_received_ts = 204.852982
last_seq = 7988
current_ts = 204.872559
current_received_ts = 204.871887
current_seq = 7989
count = 68
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.872559
last_received_ts = 204.871887
last_seq = 7989
current_ts = 204.891525
current_received_ts = 204.890945
current_seq = 7990
count = 69
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 45us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.891525
last_received_ts = 204.890945
last_seq = 7990
current_ts = 204.910507
current_received_ts = 204.909897
current_seq = 7991
count = 70
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.910507
last_received_ts = 204.909897
last_seq = 7991
current_ts = 204.929474
current_received_ts = 204.928879
current_seq = 7992
count = 71
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.929474
last_received_ts = 204.928879
last_seq = 7992
current_ts = 204.948441
current_received_ts = 204.947876
current_seq = 7993
count = 72
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 28us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.948441
last_received_ts = 204.947876
last_seq = 7993
current_ts = 204.967422
current_received_ts = 204.966827
current_seq = 7994
count = 73
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 30us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.967422
last_received_ts = 204.966827
last_seq = 7994
current_ts = 204.986404
current_received_ts = 204.985733
current_seq = 7995
count = 74
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 204.986404
last_received_ts = 204.985733
last_seq = 7995
current_ts = 205.005356
current_received_ts = 205.004822
current_seq = 7996
count = 75
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.005356
last_received_ts = 205.004822
last_seq = 7996
current_ts = 205.024353
current_received_ts = 205.023788
current_seq = 7997
count = 76
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.024353
last_received_ts = 205.023788
last_seq = 7997
current_ts = 205.043320
current_received_ts = 205.042725
current_seq = 7998
count = 77
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.043320
last_received_ts = 205.042725
last_seq = 7998
current_ts = 205.062302
current_received_ts = 205.061691
current_seq = 7999
count = 78
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.062302
last_received_ts = 205.061691
last_seq = 7999
current_ts = 205.081268
current_received_ts = 205.080719
current_seq = 8000
count = 79
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.081268
last_received_ts = 205.080719
last_seq = 8000
current_ts = 205.100250
current_received_ts = 205.099579
current_seq = 8001
count = 80
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 41us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.100250
last_received_ts = 205.099579
last_seq = 8001
current_ts = 205.119217
current_received_ts = 205.118576
current_seq = 8002
count = 81
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 50us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.119217
last_received_ts = 205.118576
last_seq = 8002
current_ts = 205.138184
current_received_ts = 205.137604
current_seq = 8003
count = 82
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.138184
last_received_ts = 205.137604
last_seq = 8003
current_ts = 205.157166
current_received_ts = 205.156570
current_seq = 8004
count = 83
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.157166
last_received_ts = 205.156570
last_seq = 8004
current_ts = 205.176147
current_received_ts = 205.175537
current_seq = 8005
count = 84
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.176147
last_received_ts = 205.175537
last_seq = 8005
current_ts = 205.195114
current_received_ts = 205.194519
current_seq = 8006
count = 85
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.195114
last_received_ts = 205.194519
last_seq = 8006
current_ts = 205.214081
current_received_ts = 205.213455
current_seq = 8007
count = 86
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 40us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.214081
last_received_ts = 205.213455
last_seq = 8007
current_ts = 205.233063
current_received_ts = 205.232407
current_seq = 8008
count = 87
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.233063
last_received_ts = 205.232407
last_seq = 8008
current_ts = 205.252045
current_received_ts = 205.251389
current_seq = 8009
count = 88
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.252045
last_received_ts = 205.251389
last_seq = 8009
current_ts = 205.270996
current_received_ts = 205.270508
current_seq = 8010
count = 89
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.270996
last_received_ts = 205.270508
last_seq = 8010
current_ts = 205.289993
current_received_ts = 205.289383
current_seq = 8011
count = 90
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.289993
last_received_ts = 205.289383
last_seq = 8011
current_ts = 205.308960
current_received_ts = 205.308350
current_seq = 8012
count = 91
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.308960
last_received_ts = 205.308350
last_seq = 8012
current_ts = 205.327927
current_received_ts = 205.327301
current_seq = 8013
count = 92
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 40us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.327927
last_received_ts = 205.327301
last_seq = 8013
current_ts = 205.346909
current_received_ts = 205.346313
current_seq = 8014
count = 93
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 27us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.346909
last_received_ts = 205.346313
last_seq = 8014
current_ts = 205.365891
current_received_ts = 205.365280
current_seq = 8015
count = 94
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.365891
last_received_ts = 205.365280
last_seq = 8015
current_ts = 205.384842
current_received_ts = 205.384232
current_seq = 8016
count = 95
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 30us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.384842
last_received_ts = 205.384232
last_seq = 8016
current_ts = 205.403824
current_received_ts = 205.403183
current_seq = 8017
count = 96
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.403824
last_received_ts = 205.403183
last_seq = 8017
current_ts = 205.422806
current_received_ts = 205.422180
current_seq = 8018
count = 97
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 43us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.422806
last_received_ts = 205.422180
last_seq = 8018
current_ts = 205.441772
current_received_ts = 205.441177
current_seq = 8019
count = 98
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.441772
last_received_ts = 205.441177
last_seq = 8019
current_ts = 205.460739
current_received_ts = 205.460236
current_seq = 8020
count = 99
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.460739
last_received_ts = 205.460236
last_seq = 8020
current_ts = 205.479736
current_received_ts = 205.479111
current_seq = 8021
count = 100
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.479736
last_received_ts = 205.479111
last_seq = 8021
current_ts = 205.498703
current_received_ts = 205.498123
current_seq = 8022
count = 101
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 27us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.498703
last_received_ts = 205.498123
last_seq = 8022
current_ts = 205.517670
current_received_ts = 205.517212
current_seq = 8023
count = 102
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.517670
last_received_ts = 205.517212
last_seq = 8023
current_ts = 205.536636
current_received_ts = 205.536041
current_seq = 8024
count = 103
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.536636
last_received_ts = 205.536041
last_seq = 8024
current_ts = 205.555618
current_received_ts = 205.554962
current_seq = 8025
count = 104
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 63us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.555618
last_received_ts = 205.554962
last_seq = 8025
current_ts = 205.574600
current_received_ts = 205.574081
current_seq = 8026
count = 105
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.574600
last_received_ts = 205.574081
last_seq = 8026
current_ts = 205.593582
current_received_ts = 205.592987
current_seq = 8027
count = 106
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.593582
last_received_ts = 205.592987
last_seq = 8027
current_ts = 205.612549
current_received_ts = 205.611938
current_seq = 8028
count = 107
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 52us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.612549
last_received_ts = 205.611938
last_seq = 8028
current_ts = 205.631516
current_received_ts = 205.630920
current_seq = 8029
count = 108
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.631516
last_received_ts = 205.630920
last_seq = 8029
current_ts = 205.650482
current_received_ts = 205.649872
current_seq = 8030
count = 109
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.650482
last_received_ts = 205.649872
last_seq = 8030
current_ts = 205.669479
current_received_ts = 205.668808
current_seq = 8031
count = 110
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.669479
last_received_ts = 205.668808
last_seq = 8031
current_ts = 205.688446
current_received_ts = 205.687820
current_seq = 8032
count = 111
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.688446
last_received_ts = 205.687820
last_seq = 8032
current_ts = 205.707413
current_received_ts = 205.706924
current_seq = 8033
count = 112
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.707413
last_received_ts = 205.706924
last_seq = 8033
current_ts = 205.726395
current_received_ts = 205.725784
current_seq = 8034
count = 113
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.726395
last_received_ts = 205.725784
last_seq = 8034
current_ts = 205.745377
current_received_ts = 205.744934
current_seq = 8035
count = 114
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.745377
last_received_ts = 205.744934
last_seq = 8035
current_ts = 205.764343
current_received_ts = 205.763718
current_seq = 8036
count = 115
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.764343
last_received_ts = 205.763718
last_seq = 8036
current_ts = 205.783310
current_received_ts = 205.782715
current_seq = 8037
count = 116
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.783310
last_received_ts = 205.782715
last_seq = 8037
current_ts = 205.802292
current_received_ts = 205.801712
current_seq = 8038
count = 117
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.802292
last_received_ts = 205.801712
last_seq = 8038
current_ts = 205.821259
current_received_ts = 205.820663
current_seq = 8039
count = 118
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.821259
last_received_ts = 205.820663
last_seq = 8039
current_ts = 205.840225
current_received_ts = 205.839615
current_seq = 8040
count = 119
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 28us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.840225
last_received_ts = 205.839615
last_seq = 8040
current_ts = 205.859207
current_received_ts = 205.858658
current_seq = 8041
count = 120
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 30us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.859207
last_received_ts = 205.858658
last_seq = 8041
current_ts = 205.878174
current_received_ts = 205.877548
current_seq = 8042
count = 121
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.878174
last_received_ts = 205.877548
last_seq = 8042
current_ts = 205.897156
current_received_ts = 205.896530
current_seq = 8043
count = 122
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.897156
last_received_ts = 205.896530
last_seq = 8043
current_ts = 205.916122
current_received_ts = 205.915543
current_seq = 8044
count = 123
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 28us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.916122
last_received_ts = 205.915543
last_seq = 8044
current_ts = 205.935104
current_received_ts = 205.934494
current_seq = 8045
count = 124
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.935104
last_received_ts = 205.934494
last_seq = 8045
current_ts = 205.954086
current_received_ts = 205.953430
current_seq = 8046
count = 125
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.954086
last_received_ts = 205.953430
last_seq = 8046
current_ts = 205.973038
current_received_ts = 205.972565
current_seq = 8047
count = 126
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.973038
last_received_ts = 205.972565
last_seq = 8047
current_ts = 205.992035
current_received_ts = 205.991409
current_seq = 8048
count = 127
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 205.992035
last_received_ts = 205.991409
last_seq = 8048
current_ts = 206.011002
current_received_ts = 206.010345
current_seq = 8049
count = 128
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 30us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.011002
last_received_ts = 206.010345
last_seq = 8049
current_ts = 206.029984
current_received_ts = 206.029373
current_seq = 8050
count = 129
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.029984
last_received_ts = 206.029373
last_seq = 8050
current_ts = 206.048950
current_received_ts = 206.048325
current_seq = 8051
count = 130
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 28us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.048950
last_received_ts = 206.048325
last_seq = 8051
current_ts = 206.067932
current_received_ts = 206.067337
current_seq = 8052
count = 131
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.067932
last_received_ts = 206.067337
last_seq = 8052
current_ts = 206.086899
current_received_ts = 206.086273
current_seq = 8053
count = 132
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.086899
last_received_ts = 206.086273
last_seq = 8053
current_ts = 206.105881
current_received_ts = 206.105331
current_seq = 8054
count = 133
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.105881
last_received_ts = 206.105331
last_seq = 8054
current_ts = 206.124832
current_received_ts = 206.124207
current_seq = 8055
count = 134
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 27us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.124832
last_received_ts = 206.124207
last_seq = 8055
current_ts = 206.143814
current_received_ts = 206.143234
current_seq = 8056
count = 135
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.143814
last_received_ts = 206.143234
last_seq = 8056
current_ts = 206.162796
current_received_ts = 206.162247
current_seq = 8057
count = 136
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.162796
last_received_ts = 206.162247
last_seq = 8057
current_ts = 206.181763
current_received_ts = 206.181244
current_seq = 8058
count = 137
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.181763
last_received_ts = 206.181244
last_seq = 8058
current_ts = 206.200745
current_received_ts = 206.200180
current_seq = 8059
count = 138
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 27us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.200745
last_received_ts = 206.200180
last_seq = 8059
current_ts = 206.219711
current_received_ts = 206.219116
current_seq = 8060
count = 139
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.219711
last_received_ts = 206.219116
last_seq = 8060
current_ts = 206.238678
current_received_ts = 206.238068
current_seq = 8061
count = 140
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.238678
last_received_ts = 206.238068
last_seq = 8061
current_ts = 206.257675
current_received_ts = 206.257721
current_seq = 8062
count = 141
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.257675
last_received_ts = 206.257721
last_seq = 8062
current_ts = 206.276642
current_received_ts = 206.276154
current_seq = 8063
count = 142
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.276642
last_received_ts = 206.276154
last_seq = 8063
current_ts = 206.295609
current_received_ts = 206.295044
current_seq = 8064
count = 143
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.295609
last_received_ts = 206.295044
last_seq = 8064
current_ts = 206.314590
current_received_ts = 206.314163
current_seq = 8065
count = 144
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.314590
last_received_ts = 206.314163
last_seq = 8065
current_ts = 206.333572
current_received_ts = 206.332977
current_seq = 8066
count = 145
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.333572
last_received_ts = 206.332977
last_seq = 8066
current_ts = 206.352539
current_received_ts = 206.351913
current_seq = 8067
count = 146
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.352539
last_received_ts = 206.351913
last_seq = 8067
current_ts = 206.371506
current_received_ts = 206.370834
current_seq = 8068
count = 147
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 27us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.371506
last_received_ts = 206.370834
last_seq = 8068
current_ts = 206.390472
current_received_ts = 206.389893
current_seq = 8069
count = 148
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 66us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.390472
last_received_ts = 206.389893
last_seq = 8069
current_ts = 206.409470
current_received_ts = 206.408875
current_seq = 8070
count = 149
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.409470
last_received_ts = 206.408875
last_seq = 8070
current_ts = 206.428421
current_received_ts = 206.427826
current_seq = 8071
count = 150
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 27us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.428421
last_received_ts = 206.427826
last_seq = 8071
current_ts = 206.447403
current_received_ts = 206.446854
current_seq = 8072
count = 151
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.447403
last_received_ts = 206.446854
last_seq = 8072
current_ts = 206.466385
current_received_ts = 206.465790
current_seq = 8073
count = 152
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.466385
last_received_ts = 206.465790
last_seq = 8073
current_ts = 206.485367
current_received_ts = 206.484695
current_seq = 8074
count = 153
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.485367
last_received_ts = 206.484695
last_seq = 8074
current_ts = 206.504318
current_received_ts = 206.503738
current_seq = 8075
count = 154
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.504318
last_received_ts = 206.503738
last_seq = 8075
current_ts = 206.523300
current_received_ts = 206.522736
current_seq = 8076
count = 155
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 29us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.523300
last_received_ts = 206.522736
last_seq = 8076
current_ts = 206.542282
current_received_ts = 206.541687
current_seq = 8077
count = 156
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.542282
last_received_ts = 206.541687
last_seq = 8077
current_ts = 206.561249
current_received_ts = 206.560669
current_seq = 8078
count = 157
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.561249
last_received_ts = 206.560669
last_seq = 8078
current_ts = 206.580231
current_received_ts = 206.579681
current_seq = 8079
count = 158
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.580231
last_received_ts = 206.579681
last_seq = 8079
current_ts = 206.599197
current_received_ts = 206.598587
current_seq = 8080
count = 159
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 28us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.599197
last_received_ts = 206.598587
last_seq = 8080
current_ts = 206.618179
current_received_ts = 206.617508
current_seq = 8081
count = 160
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.618179
last_received_ts = 206.617508
last_seq = 8081
current_ts = 206.637146
current_received_ts = 206.636566
current_seq = 8082
count = 161
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.637146
last_received_ts = 206.636566
last_seq = 8082
current_ts = 206.656113
current_received_ts = 206.655579
current_seq = 8083
count = 162
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.656113
last_received_ts = 206.655579
last_seq = 8083
current_ts = 206.675095
current_received_ts = 206.674515
current_seq = 8084
count = 163
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.675095
last_received_ts = 206.674515
last_seq = 8084
current_ts = 206.694077
current_received_ts = 206.693481
current_seq = 8085
count = 164
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.694077
last_received_ts = 206.693481
last_seq = 8085
current_ts = 206.713043
current_received_ts = 206.712387
current_seq = 8086
count = 165
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.713043
last_received_ts = 206.712387
last_seq = 8086
current_ts = 206.732025
current_received_ts = 206.731461
current_seq = 8087
count = 166
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.732025
last_received_ts = 206.731461
last_seq = 8087
current_ts = 206.750992
current_received_ts = 206.750366
current_seq = 8088
count = 167
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 27us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.750992
last_received_ts = 206.750366
last_seq = 8088
current_ts = 206.769974
current_received_ts = 206.769348
current_seq = 8089
count = 168
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.769974
last_received_ts = 206.769348
last_seq = 8089
current_ts = 206.788940
current_received_ts = 206.788315
current_seq = 8090
count = 169
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 31us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.788940
last_received_ts = 206.788315
last_seq = 8090
current_ts = 206.807907
current_received_ts = 206.807281
current_seq = 8091
count = 170
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 28us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.807907
last_received_ts = 206.807281
last_seq = 8091
current_ts = 206.826889
current_received_ts = 206.826355
current_seq = 8092
count = 171
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 32us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.826889
last_received_ts = 206.826355
last_seq = 8092
current_ts = 206.845856
current_received_ts = 206.845261
current_seq = 8093
count = 172
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.845856
last_received_ts = 206.845261
last_seq = 8093
current_ts = 206.864838
current_received_ts = 206.864258
current_seq = 8094
count = 173
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.864838
last_received_ts = 206.864258
last_seq = 8094
current_ts = 206.883804
current_received_ts = 206.883240
current_seq = 8095
count = 174
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.883804
last_received_ts = 206.883240
last_seq = 8095
current_ts = 206.902786
current_received_ts = 206.902145
current_seq = 8096
count = 175
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.902786
last_received_ts = 206.902145
last_seq = 8096
current_ts = 206.921753
current_received_ts = 206.921143
current_seq = 8097
count = 176
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.921753
last_received_ts = 206.921143
last_seq = 8097
current_ts = 206.940735
current_received_ts = 206.940155
current_seq = 8098
count = 177
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.940735
last_received_ts = 206.940155
last_seq = 8098
current_ts = 206.959702
current_received_ts = 206.959183
current_seq = 8099
count = 178
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.959702
last_received_ts = 206.959183
last_seq = 8099
current_ts = 206.978683
current_received_ts = 206.978104
current_seq = 8100
count = 179
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.978683
last_received_ts = 206.978104
last_seq = 8100
current_ts = 206.997650
current_received_ts = 206.997177
current_seq = 8101
count = 180
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 34us
(kms_flip:2213) DEBUG: name = flip
last_ts = 206.997650
last_received_ts = 206.997177
last_seq = 8101
current_ts = 207.016617
current_received_ts = 207.016037
current_seq = 8102
count = 181
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 33us
(kms_flip:2213) DEBUG: name = flip
last_ts = 207.016617
last_received_ts = 207.016037
last_seq = 8102
current_ts = 207.035614
current_received_ts = 207.034958
current_seq = 8103
count = 182
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 59us
(kms_flip:2213) DEBUG: name = flip
last_ts = 207.035614
last_received_ts = 207.034958
last_seq = 8103
current_ts = 207.054581
current_received_ts = 207.054077
current_seq = 8104
count = 183
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 35us
(kms_flip:2213) DEBUG: name = flip
last_ts = 207.054581
last_received_ts = 207.054077
last_seq = 8104
current_ts = 207.073547
current_received_ts = 207.072968
current_seq = 8105
count = 184
seq_step = 1
(kms_flip:2213) DEBUG: Vblank took 828us
(kms_flip:2213) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2213) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2213) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2213) igt_core-INFO: Stack trace:
(kms_flip:2213) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2213) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2213) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2213) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2213) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2213) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2213) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2213) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A2: FAIL (3.761s)

Dmesg

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

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

<7> [203.165758] i915 0000:00:02.0: [drm:i915_gem_open [i915]]

<7> [203.166309] i915 0000:00:02.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x000001dc [0x000001dc]

<7> [203.166516] i915 0000:00:02.0: [drm:i915_gem_open [i915]]

<7> [203.170568] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:390:HDMI-A-1]

<7> [203.170575] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:390:HDMI-A-1]

<7> [203.174779] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:390:HDMI-A-1] disconnected

<7> [203.175167] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:404:DP-1]

<7> [203.175172] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:404:DP-1]

<7> [203.179367] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:404:DP-1] disconnected

<7> [203.179611] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:HDMI-A-3]

<7> [203.179615] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:412:HDMI-A-3]

<7> [203.183821] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:HDMI-A-3] disconnected

<7> [203.184124] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:390:HDMI-A-1]

<7> [203.184128] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:390:HDMI-A-1]

<7> [203.188307] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:390:HDMI-A-1] disconnected

<7> [203.188318] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:HDMI-A-2]

<7> [203.188322] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:400:HDMI-A-2]

<7> [203.214075] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:400:HDMI-A-2] Supported Monitor Refresh rate range is 0 Hz - 0 Hz

<7> [203.214083] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:400:HDMI-A-2] Assigning EDID-1.4 digital sink color depth as 8 bpc.

<7> [203.214086] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:400:HDMI-A-2] ELD monitor fitHeadless4k

<7> [203.214088] i915 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:400:HDMI-A-2] ELD size 36, SAD count 0

<7> [203.214296] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK for addr: 0040 w(1)

<7> [203.214420] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK on first message, retry

<7> [203.214725] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus tc1] NAK for addr: 0040 w(1)

<7> [203.214848] i915 0000:00:02.0: [drm:drm_dp_dual_mode_detect [drm_display_helper]] DP dual mode HDMI ID: (err -6)

<7> [203.215219] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1366x768": 216 268000 1366 1414 1446 1526 768 771 777 814 0x40 0x6 (CLOCK_HIGH)

<7> [203.215225] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74250 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE)

<7> [203.215230] i915 0000:00:02.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74176 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE)

<7> [203.215236] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:HDMI-A-2] probed modes:

<7> [203.215239] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5

<7> [203.215243] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "4088x2304": 10 108000 4088 4152 4280 4536 2304 2305 2308 2340 0x40 0x5

<7> [203.215246] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "3840x2160": 15 128430 3840 3889 3921 4000 2160 2163 2169 2195 0x40 0xa

<7> [203.215250] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 11 60000 2880 2888 2984 3040 1800 1802 1820 1845 0x40 0xa

<7> [203.215253] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1600": 13 60000 2560 2568 2664 2720 1600 1602 1620 1645 0x40 0xa

<7> [203.215256] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2560x1440": 15 60000 2560 2568 2664 2720 1440 1442 1460 1485 0x40 0xa

<7> [203.215259] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2048x1536": 17 60000 2048 2056 2152 2208 1536 1538 1556 1581 0x40 0xa

<7> [203.215263] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1600x1200": 60 162000 1600 1664 1856 2160 1200 1201 1204 1250 0x40 0x5

<7> [203.215266] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1680x1050": 60 146250 1680 1784 1960 2240 1050 1053 1059 1089 0x40 0x6

<7> [203.215269] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1600x900": 60 108000 1600 1624 1704 1800 900 901 904 1000 0x40 0x5

<7> [203.215272] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x1024": 75 135000 1280 1296 1440 1688 1024 1025 1028 1066 0x40 0x5

<7> [203.215276] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1360x768": 60 84963 1366 1431 1567 1776 768 771 781 798 0x0 0x6

<7> [203.215279] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1360x768": 20 25190 1360 1368 1464 1520 768 770 788 813 0x40 0xa

<7> [203.215282] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x800": 60 83500 1280 1352 1480 1680 800 803 809 831 0x40 0x6

<7> [203.215285] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1152x864": 75 108000 1152 1216 1344 1600 864 865 868 900 0x40 0x5

<7> [203.215289] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5

<7> [203.215292] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5

<7> [203.215295] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74176 1280 1390 1430 1650 720 725 730 750 0x40 0x5

<7> [203.215298] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 75 78750 1024 1040 1136 1312 768 769 772 800 0x40 0x5

<7> [203.215301] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 60 65000 1024 1048 1184 1344 768 771 777 806 0x40 0xa

<7> [203.215305] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1440x480": 60 54054 1440 1472 1596 1716 480 489 495 525 0x40 0xa

<7> [203.215308] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1440x480": 60 54000 1440 1472 1596 1716 480 489 495 525 0x40 0xa

<7> [203.215311] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x576": 60 46560 1024 1064 1160 1296 576 579 584 599 0x0 0x6

<7> [203.215314] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "832x624": 75 57284 832 864 928 1152 624 625 628 667 0x40 0xa

<7> [203.215317] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 75 49500 800 816 896 1056 600 601 604 625 0x40 0x5

<7> [203.215320] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 60 40000 800 840 968 1056 600 601 605 628 0x40 0x5

<7> [203.215323] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 75 31500 640 656 720 840 480 481 484 500 0x40 0xa

<7> [203.215327] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25200 640 656 752 800 480 490 492 525 0x40 0xa

<7> [203.215330] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa

<7> [203.215333] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa

<7> [203.215336] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "720x400": 70 28320 720 738 846 900 400 412 414 449 0x40 0x6

<7> [203.215359] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:404:DP-1]

<7> [203.215363] i915 0000:00:02.0: [drm:intel_dp_detect [i915]] [CONNECTOR:404:DP-1]

<7> [203.219531] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:404:DP-1] disconnected

<7> [203.219544] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:HDMI-A-3]

<7> [203.219547] i915 0000:00:02.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:412:HDMI-A-3]

<7> [203.223735] i915 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:HDMI-A-3] disconnected

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

<6> [203.229975] [IGT] kms_flip: starting dynamic subtest A-HDMI-A2

<7> [203.230320] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:417]

<7> [203.230413] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:419]

<7> [203.273846] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [203.279478] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0

<7> [203.279630] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 2016) -> ( 0 - 0), size 2016 -> 0

<7> [203.279761] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb (2016 - 2048) -> ( 0 - 0), size 32 -> 0

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

<7> [203.280033] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [203.280165] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [203.280295] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

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

<7> [203.280574] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 0

<7> [203.280709] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1

<7> [203.280861] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 69965 kHz -> 0 kHz

<7> [203.281022] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 26237 kHz -> 0 kHz

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

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

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

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

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

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

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

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

<7> [203.313096] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC1

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

<7> [203.314172] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0

<7> [203.314644] i915 0000:00:02.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:35:plane 1A]

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

<7> [203.315583] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]

<7> [203.316085] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]

<7> [203.316521] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]

<7> [203.316977] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]

<7> [203.317415] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]

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

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

<7> [203.318850] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3

<7> [203.319328] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]

<7> [203.320255] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]

<7> [203.320548] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]

<7> [203.320819] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

<7> [203.321017] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:400:HDMI-A-2] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)

<7> [203.321304] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)

<7> [203.321558] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0

<7> [203.321834] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:399:DDI TC1/PHY C] [CRTC:151:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [203.329644] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x1

<7> [203.329817] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 2016), size 0 -> 2016

<7> [203.329971] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (2016 - 2048), size 0 -> 32

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

<7> [203.330266] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 2, 2, 2, 2, 5, 8, 9, 0, 0, 0

<7> [203.330395] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 33, 33, 33, 33, 81, 129, 145, 30, 0, 0

<7> [203.330523] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 38, 38, 38, 38, 91, 143, 161, 31, 0, 0

<7> [203.330662] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 559716 num active planes 1

<7> [203.330798] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 16761 required 560

<7> [203.330931] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1

<7> [203.331134] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 69965 kHz

<7> [203.331279] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 0 kHz -> 8746 kHz

<7> [203.331413] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:151:pipe A] allocated DPLL 0

<7> [203.331549] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:151:pipe A] reserving DPLL 0

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

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

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

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

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

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

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

<7> [203.332625] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0

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

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

<7> [203.333026] i915 0000:00:02.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> [203.333158] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1125, vmax vtotal: 1125

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

<7> [203.333418] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5

<7> [203.333549] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 53 139930 1920 2008 2096 2360 1080 1084 1089 1125 0x48 0x5

<7> [203.333679] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [203.333810] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 53 139929 1920 2008 2096 2360 1080 1084 1089 1125 0x40 0x5

<7> [203.333941] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=139929, hd=1920 hb=1920-2360 hs=2008-2096 ht=2360, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [203.334084] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 139929, pixel rate 139929, min cdclk 69965, min voltage level 0

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

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

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

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

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

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

<7> [203.335003] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1a6655d, 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> [203.335133] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [203.338270] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3

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

<7> [203.338557] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:399:DDI TC1/PHY C]

<7> [203.338691] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:403:DDI TC2/PHY D]

<7> [203.338825] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:405:DP-MST A]

<7> [203.338967] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:406:DP-MST B]

<7> [203.339101] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:407:DP-MST C]

<7> [203.339271] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3

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

<7> [203.339633] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0

<7> [203.340054] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC1

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

<7> [203.340616] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1

<7> [203.340755] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]

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

<7> [203.360062] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]

<6> [206.991315] [IGT] kms_flip: finished subtest A-HDMI-A2, FAIL

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