Machine description: shard-dg2-1
Result:
integration-manifest git-log-oneline i915_display_info16 igt_runner16 run16 runtimes16 results16.json boot16 dmesg16
Detail | Value |
---|---|
Duration | 6.50 seconds |
Hostname |
shard-dg2-1 |
Igt-Version |
IGT-Version: 1.29-NO-GIT (x86_64) (Linux: 6.12.0-rc2-CI_DRM_15491-gc2c031e80da1+ x86_64) |
Out |
Using IGT_SRANDOM=1728498523 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: plain-flip-ts-check-interruptible Starting dynamic subtest: A-HDMI-A3 1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 Expected frametime: 16667us; measured 16439.2us +- 5.398us accuracy 0.10% vblank interval differs from modeline! expected 16666.7us, measured 16439us +- 5.398us, difference 227.4us (42.1 sigma) Stack trace: #0 ../lib/igt_core.c:2051 __igt_fail_assert() #1 ../tests/kms_flip.c:791 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1845 run_test() #3 ../tests/kms_flip.c:2114 __igt_unique____real_main2001() #4 ../tests/kms_flip.c:2001 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A3: FAIL (6.495s) |
Err |
Starting subtest: plain-flip-ts-check-interruptible Starting dynamic subtest: A-HDMI-A3 (kms_flip:1148) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674: (kms_flip:1148) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon) (kms_flip:1148) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-HDMI-A3 failed. **** DEBUG **** (kms_flip:1148) DEBUG: name = flip last_ts = 45.513050 last_received_ts = 45.512661 last_seq = 2422 current_ts = 45.529522 current_received_ts = 45.529095 current_seq = 2423 count = 57 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.513050/2422, current 45.529522/2423: elapsed=16472.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.529522 last_received_ts = 45.529095 last_seq = 2423 current_ts = 45.545979 current_received_ts = 45.545593 current_seq = 2424 count = 58 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.529522/2423, current 45.545979/2424: elapsed=16455.0us expected=16439.2us +- 82.2us, error 0.1% (kms_flip:1148) DEBUG: name = flip last_ts = 45.545979 last_received_ts = 45.545593 last_seq = 2424 current_ts = 45.562454 current_received_ts = 45.562077 current_seq = 2425 count = 59 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.545979/2424, current 45.562454/2425: elapsed=16475.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.562454 last_received_ts = 45.562077 last_seq = 2425 current_ts = 45.578918 current_received_ts = 45.578487 current_seq = 2426 count = 60 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.562454/2425, current 45.578918/2426: elapsed=16467.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.578918 last_received_ts = 45.578487 last_seq = 2426 current_ts = 45.595390 current_received_ts = 45.595131 current_seq = 2427 count = 61 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.578918/2426, current 45.595390/2427: elapsed=16469.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.595390 last_received_ts = 45.595131 last_seq = 2427 current_ts = 45.611855 current_received_ts = 45.611435 current_seq = 2428 count = 62 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.595390/2427, current 45.611855/2428: elapsed=16465.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.611855 last_received_ts = 45.611435 last_seq = 2428 current_ts = 45.628326 current_received_ts = 45.628075 current_seq = 2429 count = 63 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.611855/2428, current 45.628326/2429: elapsed=16474.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.628326 last_received_ts = 45.628075 last_seq = 2429 current_ts = 45.644787 current_received_ts = 45.644283 current_seq = 2430 count = 64 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.628326/2429, current 45.644787/2430: elapsed=16460.0us expected=16439.2us +- 82.2us, error 0.1% (kms_flip:1148) DEBUG: name = flip last_ts = 45.644787 last_received_ts = 45.644283 last_seq = 2430 current_ts = 45.661255 current_received_ts = 45.660988 current_seq = 2431 count = 65 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.644787/2430, current 45.661255/2431: elapsed=16466.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.661255 last_received_ts = 45.660988 last_seq = 2431 current_ts = 45.677731 current_received_ts = 45.677265 current_seq = 2432 count = 66 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.661255/2431, current 45.677731/2432: elapsed=16477.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.677731 last_received_ts = 45.677265 last_seq = 2432 current_ts = 45.694195 current_received_ts = 45.693916 current_seq = 2433 count = 67 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.677731/2432, current 45.694195/2433: elapsed=16464.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.694195 last_received_ts = 45.693916 last_seq = 2433 current_ts = 45.710663 current_received_ts = 45.710258 current_seq = 2434 count = 68 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.694195/2433, current 45.710663/2434: elapsed=16467.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.710663 last_received_ts = 45.710258 last_seq = 2434 current_ts = 45.727127 current_received_ts = 45.726715 current_seq = 2435 count = 69 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.710663/2434, current 45.727127/2435: elapsed=16466.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.727127 last_received_ts = 45.726715 last_seq = 2435 current_ts = 45.743603 current_received_ts = 45.743172 current_seq = 2436 count = 70 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.727127/2435, current 45.743603/2436: elapsed=16473.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.743603 last_received_ts = 45.743172 last_seq = 2436 current_ts = 45.760063 current_received_ts = 45.759682 current_seq = 2437 count = 71 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.743603/2436, current 45.760063/2437: elapsed=16464.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.760063 last_received_ts = 45.759682 last_seq = 2437 current_ts = 45.776531 current_received_ts = 45.776257 current_seq = 2438 count = 72 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.760063/2437, current 45.776531/2438: elapsed=16465.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.776531 last_received_ts = 45.776257 last_seq = 2438 current_ts = 45.793003 current_received_ts = 45.792629 current_seq = 2439 count = 73 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.776531/2438, current 45.793003/2439: elapsed=16474.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.793003 last_received_ts = 45.792629 last_seq = 2439 current_ts = 45.809467 current_received_ts = 45.809196 current_seq = 2440 count = 74 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.793003/2439, current 45.809467/2440: elapsed=16462.0us expected=16439.2us +- 82.2us, error 0.1% (kms_flip:1148) DEBUG: name = flip last_ts = 45.809467 last_received_ts = 45.809196 last_seq = 2440 current_ts = 45.825932 current_received_ts = 45.825451 current_seq = 2441 count = 75 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.809467/2440, current 45.825932/2441: elapsed=16467.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.825932 last_received_ts = 45.825451 last_seq = 2441 current_ts = 45.842400 current_received_ts = 45.842136 current_seq = 2442 count = 76 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.825932/2441, current 45.842400/2442: elapsed=16467.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.842400 last_received_ts = 45.842136 last_seq = 2442 current_ts = 45.858875 current_received_ts = 45.858406 current_seq = 2443 count = 77 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.842400/2442, current 45.858875/2443: elapsed=16477.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.858875 last_received_ts = 45.858406 last_seq = 2443 current_ts = 45.875332 current_received_ts = 45.875084 current_seq = 2444 count = 78 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.858875/2443, current 45.875332/2444: elapsed=16456.0us expected=16439.2us +- 82.2us, error 0.1% (kms_flip:1148) DEBUG: name = flip last_ts = 45.875332 last_received_ts = 45.875084 last_seq = 2444 current_ts = 45.891811 current_received_ts = 45.891346 current_seq = 2445 count = 79 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.875332/2444, current 45.891811/2445: elapsed=16478.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.891811 last_received_ts = 45.891346 last_seq = 2445 current_ts = 45.908264 current_received_ts = 45.908024 current_seq = 2446 count = 80 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.891811/2445, current 45.908264/2446: elapsed=16452.0us expected=16439.2us +- 82.2us, error 0.1% (kms_flip:1148) DEBUG: name = flip last_ts = 45.908264 last_received_ts = 45.908024 last_seq = 2446 current_ts = 45.924736 current_received_ts = 45.924297 current_seq = 2447 count = 81 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.908264/2446, current 45.924736/2447: elapsed=16473.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.924736 last_received_ts = 45.924297 last_seq = 2447 current_ts = 45.941208 current_received_ts = 45.940929 current_seq = 2448 count = 82 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.924736/2447, current 45.941208/2448: elapsed=16471.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.941208 last_received_ts = 45.940929 last_seq = 2448 current_ts = 45.957680 current_received_ts = 45.957260 current_seq = 2449 count = 83 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.941208/2448, current 45.957680/2449: elapsed=16471.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.957680 last_received_ts = 45.957260 last_seq = 2449 current_ts = 45.974144 current_received_ts = 45.973728 current_seq = 2450 count = 84 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.957680/2449, current 45.974144/2450: elapsed=16465.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.974144 last_received_ts = 45.973728 last_seq = 2450 current_ts = 45.990608 current_received_ts = 45.990208 current_seq = 2451 count = 85 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.974144/2450, current 45.990608/2451: elapsed=16466.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 45.990608 last_received_ts = 45.990208 last_seq = 2451 current_ts = 46.007076 current_received_ts = 46.006676 current_seq = 2452 count = 86 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 45.990608/2451, current 46.007076/2452: elapsed=16467.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 46.007076 last_received_ts = 46.006676 last_seq = 2452 current_ts = 46.023540 current_received_ts = 46.023144 current_seq = 2453 count = 87 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.007076/2452, current 46.023540/2453: elapsed=16464.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 46.023540 last_received_ts = 46.023144 last_seq = 2453 current_ts = 46.040005 current_received_ts = 46.039635 current_seq = 2454 count = 88 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.023540/2453, current 46.040005/2454: elapsed=16466.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 46.040005 last_received_ts = 46.039635 last_seq = 2454 current_ts = 46.056480 current_received_ts = 46.056095 current_seq = 2455 count = 89 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.040005/2454, current 46.056480/2455: elapsed=16473.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 46.056480 last_received_ts = 46.056095 last_seq = 2455 current_ts = 46.072948 current_received_ts = 46.072536 current_seq = 2456 count = 90 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.056480/2455, current 46.072948/2456: elapsed=16469.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 46.072948 last_received_ts = 46.072536 last_seq = 2456 current_ts = 46.089436 current_received_ts = 46.089149 current_seq = 2457 count = 91 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.072948/2456, current 46.089436/2457: elapsed=16487.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.089436 last_received_ts = 46.089149 last_seq = 2457 current_ts = 46.105927 current_received_ts = 46.105461 current_seq = 2458 count = 92 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.089436/2457, current 46.105927/2458: elapsed=16490.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.105927 last_received_ts = 46.105461 last_seq = 2458 current_ts = 46.122417 current_received_ts = 46.122143 current_seq = 2459 count = 93 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.105927/2458, current 46.122417/2459: elapsed=16493.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.122417 last_received_ts = 46.122143 last_seq = 2459 current_ts = 46.138920 current_received_ts = 46.138409 current_seq = 2460 count = 94 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.122417/2459, current 46.138920/2460: elapsed=16501.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.138920 last_received_ts = 46.138409 last_seq = 2460 current_ts = 46.155403 current_received_ts = 46.155136 current_seq = 2461 count = 95 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.138920/2460, current 46.155403/2461: elapsed=16485.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.155403 last_received_ts = 46.155136 last_seq = 2461 current_ts = 46.171894 current_received_ts = 46.171555 current_seq = 2462 count = 96 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.155403/2461, current 46.171894/2462: elapsed=16490.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.171894 last_received_ts = 46.171555 last_seq = 2462 current_ts = 46.188389 current_received_ts = 46.188133 current_seq = 2463 count = 97 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.171894/2462, current 46.188389/2463: elapsed=16493.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.188389 last_received_ts = 46.188133 last_seq = 2463 current_ts = 46.204884 current_received_ts = 46.204548 current_seq = 2464 count = 98 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.188389/2463, current 46.204884/2464: elapsed=16497.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.204884 last_received_ts = 46.204548 last_seq = 2464 current_ts = 46.221371 current_received_ts = 46.220959 current_seq = 2465 count = 99 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.204884/2464, current 46.221371/2465: elapsed=16487.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.221371 last_received_ts = 46.220959 last_seq = 2465 current_ts = 46.237865 current_received_ts = 46.237530 current_seq = 2466 count = 100 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.221371/2465, current 46.237865/2466: elapsed=16496.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.237865 last_received_ts = 46.237530 last_seq = 2466 current_ts = 46.254360 current_received_ts = 46.254036 current_seq = 2467 count = 101 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.237865/2466, current 46.254360/2467: elapsed=16494.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.254360 last_received_ts = 46.254036 last_seq = 2467 current_ts = 46.270851 current_received_ts = 46.270424 current_seq = 2468 count = 102 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.254360/2467, current 46.270851/2468: elapsed=16491.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.270851 last_received_ts = 46.270424 last_seq = 2468 current_ts = 46.287342 current_received_ts = 46.286884 current_seq = 2469 count = 103 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.270851/2468, current 46.287342/2469: elapsed=16489.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.287342 last_received_ts = 46.286884 last_seq = 2469 current_ts = 46.303844 current_received_ts = 46.303410 current_seq = 2470 count = 104 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.287342/2469, current 46.303844/2470: elapsed=16502.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.303844 last_received_ts = 46.303410 last_seq = 2470 current_ts = 46.320332 current_received_ts = 46.319897 current_seq = 2471 count = 105 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.303844/2470, current 46.320332/2471: elapsed=16488.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.320332 last_received_ts = 46.319897 last_seq = 2471 current_ts = 46.336819 current_received_ts = 46.336403 current_seq = 2472 count = 106 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.320332/2471, current 46.336819/2472: elapsed=16487.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.336819 last_received_ts = 46.336403 last_seq = 2472 current_ts = 46.353310 current_received_ts = 46.352901 current_seq = 2473 count = 107 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.336819/2472, current 46.353310/2473: elapsed=16491.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.353310 last_received_ts = 46.352901 last_seq = 2473 current_ts = 46.369804 current_received_ts = 46.369396 current_seq = 2474 count = 108 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.353310/2473, current 46.369804/2474: elapsed=16494.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.369804 last_received_ts = 46.369396 last_seq = 2474 current_ts = 46.386299 current_received_ts = 46.386063 current_seq = 2475 count = 109 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.369804/2474, current 46.386299/2475: elapsed=16495.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.386299 last_received_ts = 46.386063 last_seq = 2475 current_ts = 46.402790 current_received_ts = 46.402374 current_seq = 2476 count = 110 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.386299/2475, current 46.402790/2476: elapsed=16493.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.402790 last_received_ts = 46.402374 last_seq = 2476 current_ts = 46.419281 current_received_ts = 46.419041 current_seq = 2477 count = 111 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.402790/2476, current 46.419281/2477: elapsed=16490.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.419281 last_received_ts = 46.419041 last_seq = 2477 current_ts = 46.435776 current_received_ts = 46.435310 current_seq = 2478 count = 112 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.419281/2477, current 46.435776/2478: elapsed=16494.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.435776 last_received_ts = 46.435310 last_seq = 2478 current_ts = 46.452274 current_received_ts = 46.451996 current_seq = 2479 count = 113 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.435776/2478, current 46.452274/2479: elapsed=16499.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.452274 last_received_ts = 46.451996 last_seq = 2479 current_ts = 46.468761 current_received_ts = 46.468269 current_seq = 2480 count = 114 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.452274/2479, current 46.468761/2480: elapsed=16486.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.468761 last_received_ts = 46.468269 last_seq = 2480 current_ts = 46.485249 current_received_ts = 46.484936 current_seq = 2481 count = 115 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.468761/2480, current 46.485249/2481: elapsed=16488.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.485249 last_received_ts = 46.484936 last_seq = 2481 current_ts = 46.501755 current_received_ts = 46.501286 current_seq = 2482 count = 116 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.485249/2481, current 46.501755/2482: elapsed=16506.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.501755 last_received_ts = 46.501286 last_seq = 2482 current_ts = 46.518246 current_received_ts = 46.517952 current_seq = 2483 count = 117 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.501755/2482, current 46.518246/2483: elapsed=16491.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.518246 last_received_ts = 46.517952 last_seq = 2483 current_ts = 46.534740 current_received_ts = 46.534275 current_seq = 2484 count = 118 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.518246/2483, current 46.534740/2484: elapsed=16494.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.534740 last_received_ts = 46.534275 last_seq = 2484 current_ts = 46.551216 current_received_ts = 46.550953 current_seq = 2485 count = 119 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.534740/2484, current 46.551216/2485: elapsed=16478.0us expected=16439.2us +- 82.2us, error 0.2% (kms_flip:1148) DEBUG: name = flip last_ts = 46.551216 last_received_ts = 46.550953 last_seq = 2485 current_ts = 46.567715 current_received_ts = 46.567230 current_seq = 2486 count = 120 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.551216/2485, current 46.567715/2486: elapsed=16499.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.567715 last_received_ts = 46.567230 last_seq = 2486 current_ts = 46.584206 current_received_ts = 46.583813 current_seq = 2487 count = 121 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.567715/2486, current 46.584206/2487: elapsed=16490.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.584206 last_received_ts = 46.583813 last_seq = 2487 current_ts = 46.600708 current_received_ts = 46.600258 current_seq = 2488 count = 122 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.584206/2487, current 46.600708/2488: elapsed=16501.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.600708 last_received_ts = 46.600258 last_seq = 2488 current_ts = 46.617203 current_received_ts = 46.616669 current_seq = 2489 count = 123 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.600708/2488, current 46.617203/2489: elapsed=16496.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.617203 last_received_ts = 46.616669 last_seq = 2489 current_ts = 46.633686 current_received_ts = 46.633396 current_seq = 2490 count = 124 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.617203/2489, current 46.633686/2490: elapsed=16482.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.633686 last_received_ts = 46.633396 last_seq = 2490 current_ts = 46.650173 current_received_ts = 46.649731 current_seq = 2491 count = 125 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.633686/2490, current 46.650173/2491: elapsed=16489.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.650173 last_received_ts = 46.649731 last_seq = 2491 current_ts = 46.666668 current_received_ts = 46.666393 current_seq = 2492 count = 126 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.650173/2491, current 46.666668/2492: elapsed=16495.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.666668 last_received_ts = 46.666393 last_seq = 2492 current_ts = 46.683163 current_received_ts = 46.682758 current_seq = 2493 count = 127 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.666668/2492, current 46.683163/2493: elapsed=16493.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.683163 last_received_ts = 46.682758 last_seq = 2493 current_ts = 46.699657 current_received_ts = 46.699413 current_seq = 2494 count = 128 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.683163/2493, current 46.699657/2494: elapsed=16496.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.699657 last_received_ts = 46.699413 last_seq = 2494 current_ts = 46.716152 current_received_ts = 46.715862 current_seq = 2495 count = 129 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.699657/2494, current 46.716152/2495: elapsed=16495.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.716152 last_received_ts = 46.715862 last_seq = 2495 current_ts = 46.732635 current_received_ts = 46.732273 current_seq = 2496 count = 130 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.716152/2495, current 46.732635/2496: elapsed=16483.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.732635 last_received_ts = 46.732273 last_seq = 2496 current_ts = 46.749138 current_received_ts = 46.748837 current_seq = 2497 count = 131 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.732635/2496, current 46.749138/2497: elapsed=16502.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.749138 last_received_ts = 46.748837 last_seq = 2497 current_ts = 46.765629 current_received_ts = 46.765118 current_seq = 2498 count = 132 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.749138/2497, current 46.765629/2498: elapsed=16489.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.765629 last_received_ts = 46.765118 last_seq = 2498 current_ts = 46.782124 current_received_ts = 46.781731 current_seq = 2499 count = 133 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.765629/2498, current 46.782124/2499: elapsed=16495.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.782124 last_received_ts = 46.781731 last_seq = 2499 current_ts = 46.798615 current_received_ts = 46.798180 current_seq = 2500 count = 134 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.782124/2499, current 46.798615/2500: elapsed=16493.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.798615 last_received_ts = 46.798180 last_seq = 2500 current_ts = 46.815109 current_received_ts = 46.814701 current_seq = 2501 count = 135 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.798615/2500, current 46.815109/2501: elapsed=16495.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.815109 last_received_ts = 46.814701 last_seq = 2501 current_ts = 46.831600 current_received_ts = 46.831161 current_seq = 2502 count = 136 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.815109/2501, current 46.831600/2502: elapsed=16491.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.831600 last_received_ts = 46.831161 last_seq = 2502 current_ts = 46.848087 current_received_ts = 46.847679 current_seq = 2503 count = 137 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.831600/2502, current 46.848087/2503: elapsed=16485.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.848087 last_received_ts = 46.847679 last_seq = 2503 current_ts = 46.864578 current_received_ts = 46.864338 current_seq = 2504 count = 138 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.848087/2503, current 46.864578/2504: elapsed=16492.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.864578 last_received_ts = 46.864338 last_seq = 2504 current_ts = 46.881073 current_received_ts = 46.880543 current_seq = 2505 count = 139 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.864578/2504, current 46.881073/2505: elapsed=16494.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.881073 last_received_ts = 46.880543 last_seq = 2505 current_ts = 46.897568 current_received_ts = 46.897236 current_seq = 2506 count = 140 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.881073/2505, current 46.897568/2506: elapsed=16497.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 46.897568 last_received_ts = 46.897236 last_seq = 2506 current_ts = 46.914059 current_received_ts = 46.913647 current_seq = 2507 count = 141 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.897568/2506, current 46.914059/2507: elapsed=16489.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.914059 last_received_ts = 46.913647 last_seq = 2507 current_ts = 46.930550 current_received_ts = 46.930309 current_seq = 2508 count = 142 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.914059/2507, current 46.930550/2508: elapsed=16492.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.930550 last_received_ts = 46.930309 last_seq = 2508 current_ts = 46.947041 current_received_ts = 46.946739 current_seq = 2509 count = 143 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.930550/2508, current 46.947041/2509: elapsed=16492.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.947041 last_received_ts = 46.946739 last_seq = 2509 current_ts = 46.963531 current_received_ts = 46.963139 current_seq = 2510 count = 144 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.947041/2509, current 46.963531/2510: elapsed=16489.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.963531 last_received_ts = 46.963139 last_seq = 2510 current_ts = 46.980022 current_received_ts = 46.979736 current_seq = 2511 count = 145 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.963531/2510, current 46.980022/2511: elapsed=16493.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.980022 last_received_ts = 46.979736 last_seq = 2511 current_ts = 46.996517 current_received_ts = 46.996025 current_seq = 2512 count = 146 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.980022/2511, current 46.996517/2512: elapsed=16493.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 46.996517 last_received_ts = 46.996025 last_seq = 2512 current_ts = 47.013020 current_received_ts = 47.012608 current_seq = 2513 count = 147 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 46.996517/2512, current 47.013020/2513: elapsed=16502.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.013020 last_received_ts = 47.012608 last_seq = 2513 current_ts = 47.029510 current_received_ts = 47.029114 current_seq = 2514 count = 148 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.013020/2513, current 47.029510/2514: elapsed=16491.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 47.029510 last_received_ts = 47.029114 last_seq = 2514 current_ts = 47.046005 current_received_ts = 47.045582 current_seq = 2515 count = 149 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.029510/2514, current 47.046005/2515: elapsed=16494.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 47.046005 last_received_ts = 47.045582 last_seq = 2515 current_ts = 47.062500 current_received_ts = 47.062206 current_seq = 2516 count = 150 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.046005/2515, current 47.062500/2516: elapsed=16496.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 47.062500 last_received_ts = 47.062206 last_seq = 2516 current_ts = 47.078983 current_received_ts = 47.078491 current_seq = 2517 count = 151 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.062500/2516, current 47.078983/2517: elapsed=16483.0us expected=16439.2us +- 82.2us, error 0.3% (kms_flip:1148) DEBUG: name = flip last_ts = 47.078983 last_received_ts = 47.078491 last_seq = 2517 current_ts = 47.095501 current_received_ts = 47.095310 current_seq = 2518 count = 152 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.078983/2517, current 47.095501/2518: elapsed=16519.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.095501 last_received_ts = 47.095310 last_seq = 2518 current_ts = 47.112015 current_received_ts = 47.111553 current_seq = 2519 count = 153 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.095501/2518, current 47.112015/2519: elapsed=16512.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.112015 last_received_ts = 47.111553 last_seq = 2519 current_ts = 47.128529 current_received_ts = 47.128296 current_seq = 2520 count = 154 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.112015/2519, current 47.128529/2520: elapsed=16516.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.128529 last_received_ts = 47.128296 last_seq = 2520 current_ts = 47.145046 current_received_ts = 47.144730 current_seq = 2521 count = 155 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.128529/2520, current 47.145046/2521: elapsed=16517.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.145046 last_received_ts = 47.144730 last_seq = 2521 current_ts = 47.161564 current_received_ts = 47.161152 current_seq = 2522 count = 156 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.145046/2521, current 47.161564/2522: elapsed=16516.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.161564 last_received_ts = 47.161152 last_seq = 2522 current_ts = 47.178078 current_received_ts = 47.177780 current_seq = 2523 count = 157 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.161564/2522, current 47.178078/2523: elapsed=16513.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.178078 last_received_ts = 47.177780 last_seq = 2523 current_ts = 47.194588 current_received_ts = 47.194160 current_seq = 2524 count = 158 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.178078/2523, current 47.194588/2524: elapsed=16511.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.194588 last_received_ts = 47.194160 last_seq = 2524 current_ts = 47.211098 current_received_ts = 47.210812 current_seq = 2525 count = 159 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.194588/2524, current 47.211098/2525: elapsed=16512.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.211098 last_received_ts = 47.210812 last_seq = 2525 current_ts = 47.227612 current_received_ts = 47.227142 current_seq = 2526 count = 160 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.211098/2525, current 47.227612/2526: elapsed=16514.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.227612 last_received_ts = 47.227142 last_seq = 2526 current_ts = 47.244129 current_received_ts = 47.243832 current_seq = 2527 count = 161 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.227612/2526, current 47.244129/2527: elapsed=16518.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.244129 last_received_ts = 47.243832 last_seq = 2527 current_ts = 47.260643 current_received_ts = 47.260189 current_seq = 2528 count = 162 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.244129/2527, current 47.260643/2528: elapsed=16513.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.260643 last_received_ts = 47.260189 last_seq = 2528 current_ts = 47.277164 current_received_ts = 47.276855 current_seq = 2529 count = 163 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.260643/2528, current 47.277164/2529: elapsed=16519.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.277164 last_received_ts = 47.276855 last_seq = 2529 current_ts = 47.293682 current_received_ts = 47.293259 current_seq = 2530 count = 164 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.277164/2529, current 47.293682/2530: elapsed=16518.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.293682 last_received_ts = 47.293259 last_seq = 2530 current_ts = 47.310192 current_received_ts = 47.309784 current_seq = 2531 count = 165 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.293682/2530, current 47.310192/2531: elapsed=16510.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.310192 last_received_ts = 47.309784 last_seq = 2531 current_ts = 47.326706 current_received_ts = 47.326248 current_seq = 2532 count = 166 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.310192/2531, current 47.326706/2532: elapsed=16515.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.326706 last_received_ts = 47.326248 last_seq = 2532 current_ts = 47.343216 current_received_ts = 47.342766 current_seq = 2533 count = 167 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.326706/2532, current 47.343216/2533: elapsed=16510.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.343216 last_received_ts = 47.342766 last_seq = 2533 current_ts = 47.359730 current_received_ts = 47.359409 current_seq = 2534 count = 168 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.343216/2533, current 47.359730/2534: elapsed=16512.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.359730 last_received_ts = 47.359409 last_seq = 2534 current_ts = 47.376247 current_received_ts = 47.375835 current_seq = 2535 count = 169 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.359730/2534, current 47.376247/2535: elapsed=16521.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.376247 last_received_ts = 47.375835 last_seq = 2535 current_ts = 47.392757 current_received_ts = 47.392399 current_seq = 2536 count = 170 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.376247/2535, current 47.392757/2536: elapsed=16509.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.392757 last_received_ts = 47.392399 last_seq = 2536 current_ts = 47.409275 current_received_ts = 47.408989 current_seq = 2537 count = 171 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.392757/2536, current 47.409275/2537: elapsed=16518.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.409275 last_received_ts = 47.408989 last_seq = 2537 current_ts = 47.425797 current_received_ts = 47.425400 current_seq = 2538 count = 172 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.409275/2537, current 47.425797/2538: elapsed=16520.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.425797 last_received_ts = 47.425400 last_seq = 2538 current_ts = 47.442299 current_received_ts = 47.442047 current_seq = 2539 count = 173 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.425797/2538, current 47.442299/2539: elapsed=16503.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.442299 last_received_ts = 47.442047 last_seq = 2539 current_ts = 47.458817 current_received_ts = 47.458298 current_seq = 2540 count = 174 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.442299/2539, current 47.458817/2540: elapsed=16518.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: name = flip last_ts = 47.458817 last_received_ts = 47.458298 last_seq = 2540 current_ts = 47.475327 current_received_ts = 47.475075 current_seq = 2541 count = 175 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.458817/2540, current 47.475327/2541: elapsed=16510.0us expected=16439.2us +- 82.2us, error 0.4% (kms_flip:1148) DEBUG: name = flip last_ts = 47.475327 last_received_ts = 47.475075 last_seq = 2541 current_ts = 47.491852 current_received_ts = 47.491505 current_seq = 2542 count = 176 seq_step = 1 (kms_flip:1148) DEBUG: flip ts/seq: last 47.475327/2541, current 47.491852/2542: elapsed=16526.0us expected=16439.2us +- 82.2us, error 0.5% (kms_flip:1148) DEBUG: inconsistent flip ts/seq: last 47.475327/2541, current 47.491852/2542: elapsed=16526.0us expected=16439.2us (kms_flip:1148) DEBUG: expected 156757, counted 176, encoder type 2 (kms_flip:1148) DEBUG: dropped frames, expected 156757, counted 176, encoder type 2 (kms_flip:1148) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674: (kms_flip:1148) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon) (kms_flip:1148) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:1148) igt_core-INFO: Stack trace: (kms_flip:1148) igt_core-INFO: #0 ../lib/igt_core.c:2051 __igt_fail_assert() (kms_flip:1148) igt_core-INFO: #1 ../tests/kms_flip.c:791 run_test_on_crtc_set.constprop.0() (kms_flip:1148) igt_core-INFO: #2 ../tests/kms_flip.c:1845 run_test() (kms_flip:1148) igt_core-INFO: #3 ../tests/kms_flip.c:2114 __igt_unique____real_main2001() (kms_flip:1148) igt_core-INFO: #4 ../tests/kms_flip.c:2001 main() (kms_flip:1148) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:1148) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:1148) igt_core-INFO: #7 [_start+0x25] **** END **** Dynamic subtest A-HDMI-A3: FAIL (6.495s) |
Dmesg |
<6> [42.131914] Console: switching to colour dummy device 80x25
<6> [42.131952] [IGT] kms_flip: executing
<7> [42.133912] i915 0000:03:00.0: [drm:i915_gem_open [i915]]
<7> [42.135107] i915 0000:03:00.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x000001dc [0x000001dc]
<7> [42.152541] i915 0000:03:00.0: [drm:i915_gem_open [i915]]
<7> [42.160672] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:241:DP-1]
<7> [42.160697] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:241:DP-1]
<7> [42.165222] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:241:DP-1] disconnected
<7> [42.165648] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:254:DP-2]
<7> [42.165652] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:254:DP-2]
<7> [42.170218] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:254:DP-2] disconnected
<7> [42.170643] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:263:HDMI-A-1]
<7> [42.170647] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:263:HDMI-A-1]
<7> [42.175232] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:263:HDMI-A-1] disconnected
<7> [42.175660] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:269:DP-3]
<7> [42.175664] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:269:DP-3]
<7> [42.180218] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:269:DP-3] disconnected
<7> [42.180637] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:277:HDMI-A-2]
<7> [42.180641] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:277:HDMI-A-2]
<7> [42.185220] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:277:HDMI-A-2] disconnected
<7> [42.185654] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:281:DP-4]
<7> [42.185658] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:281:DP-4]
<7> [42.185943] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling AUX_D
<7> [42.216212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.245217] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.271219] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.299217] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.328213] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.357212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.386212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.415212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.444212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.473213] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.502212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.531212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.560212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.589212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.618212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.647212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.676213] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.705212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.734212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.763212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.792212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.821212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.850212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.879212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.908212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.937212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.966213] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [42.995212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.024212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.053212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.082212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.111212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.111395] i915 0000:03:00.0: [drm:drm_dp_dpcd_access [drm_display_helper]] AUX D/DDI D/PHY D: Too many retries, giving up. First error: -110
<7> [43.111419] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:281:DP-4] disconnected
<7> [43.112291] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:241:DP-1]
<7> [43.112296] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:241:DP-1]
<7> [43.117217] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:241:DP-1] disconnected
<7> [43.117232] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:254:DP-2]
<7> [43.117236] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:254:DP-2]
<7> [43.122218] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:254:DP-2] disconnected
<7> [43.122232] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:263:HDMI-A-1]
<7> [43.122236] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:263:HDMI-A-1]
<7> [43.127219] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:263:HDMI-A-1] disconnected
<7> [43.127234] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:269:DP-3]
<7> [43.127237] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:269:DP-3]
<7> [43.132216] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:269:DP-3] disconnected
<7> [43.132230] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:277:HDMI-A-2]
<7> [43.132233] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:277:HDMI-A-2]
<7> [43.137218] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:277:HDMI-A-2] disconnected
<7> [43.137232] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:281:DP-4]
<7> [43.137235] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:281:DP-4]
<7> [43.166212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.195212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.224212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.253212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.282212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.311212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.340213] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.369212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.398212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.427212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.456212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.485212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.514212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.543212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.572212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.601212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.630212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.659212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.688213] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.717212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.746212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.775212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.804212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.833212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.862212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.891212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.920212] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.947700] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [43.976211] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [44.005211] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [44.034211] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [44.063211] i915 0000:03:00.0: [drm:intel_dp_aux_xfer [i915]] AUX D/DDI D/PHY D: timeout (status 0x7d40023f)
<7> [44.063403] i915 0000:03:00.0: [drm:drm_dp_dpcd_access [drm_display_helper]] AUX D/DDI D/PHY D: Too many retries, giving up. First error: -110
<7> [44.063417] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:281:DP-4] disconnected
<7> [44.063440] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:289:HDMI-A-3]
<7> [44.063445] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:289:HDMI-A-3]
<7> [44.089220] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:289:HDMI-A-3] ELD monitor FH-DP4K
<7> [44.089226] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:289:HDMI-A-3] ELD size 36, SAD count 2
<7> [44.089427] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpd] NAK for addr: 0040 w(1)
<7> [44.089592] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpd] NAK on first message, retry
<7> [44.089913] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpd] NAK for addr: 0040 w(1)
<7> [44.090067] i915 0000:03:00.0: [drm:drm_dp_dual_mode_detect [drm_display_helper]] DP dual mode HDMI ID: (err -6)
<7> [44.090079] i915 0000:03:00.0: [drm:intel_hdmi_set_edid [i915]] Assuming DP dual mode adaptor presence based on VBT
<7> [44.090233] i915 0000:03:00.0: [drm:intel_hdmi_set_edid [i915]] DP dual mode adaptor (type 1 DVI) detected (max TMDS clock: 165000 kHz)
<7> [44.090816] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "2560x1440": 60 241700 2560 2608 2640 2720 1440 1443 1448 1481 0x40 0x9 (CLOCK_HIGH)
<7> [44.090823] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "2560x1600": 60 267820 2560 2608 2640 2720 1600 1603 1608 1641 0x40 0x9 (CLOCK_HIGH)
<7> [44.090829] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "2560x1440": 30 120850 2560 2608 2640 2720 1440 1443 1448 1481 0x40 0x9 (CLOCK_RANGE)
<7> [44.090833] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "2560x1600": 30 133910 2560 2608 2640 2720 1600 1603 1608 1641 0x40 0x9 (CLOCK_RANGE)
<7> [44.090838] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080": 120 297000 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 (CLOCK_HIGH)
<7> [44.090842] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "3840x2160": 30 266640 3840 3888 3920 4000 2160 2163 2168 2222 0x40 0x9 (CLOCK_HIGH)
<7> [44.090847] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "3840x2160": 17 151100 3840 3888 3920 4000 2160 2163 2168 2222 0x40 0x9 (CLOCK_RANGE)
<7> [44.090851] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080": 120 296703 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 (CLOCK_HIGH)
<7> [44.090857] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:289:HDMI-A-3] probed modes:
<7> [44.090863] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [44.090866] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1200": 60 154000 1920 1968 2000 2080 1200 1203 1209 1235 0x40 0x9
<7> [44.090869] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1920x1080": 60 148352 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [44.090872] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1680x1050": 60 119000 1680 1728 1760 1840 1050 1053 1059 1080 0x40 0x9
<7> [44.090874] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1600x900": 60 108000 1600 1624 1704 1800 900 901 904 1000 0x40 0x5
<7> [44.090877] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x1024": 75 135000 1280 1296 1440 1688 1024 1025 1028 1066 0x40 0x5
<7> [44.090880] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x1024": 60 108000 1280 1328 1440 1688 1024 1025 1028 1066 0x40 0x5
<7> [44.090882] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1440x900": 60 88750 1440 1488 1520 1600 900 903 909 926 0x40 0x9
<7> [44.090885] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x800": 60 71000 1280 1328 1360 1440 800 803 809 823 0x40 0x9
<7> [44.090888] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1152x864": 75 108000 1152 1216 1344 1600 864 865 868 900 0x40 0x5
<7> [44.090890] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [44.090893] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1280x720": 60 74176 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [44.090896] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 75 78750 1024 1040 1136 1312 768 769 772 800 0x40 0x5
<7> [44.090898] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 70 75000 1024 1048 1184 1328 768 771 777 806 0x40 0xa
<7> [44.090901] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "1024x768": 60 65000 1024 1048 1184 1344 768 771 777 806 0x40 0xa
<7> [44.090904] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 75 49500 800 816 896 1056 600 601 604 625 0x40 0x5
<7> [44.090906] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 72 50000 800 856 976 1040 600 637 643 666 0x40 0x5
<7> [44.090909] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 60 40000 800 840 968 1056 600 601 605 628 0x40 0x5
<7> [44.090912] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "800x600": 56 36000 800 824 896 1024 600 601 603 625 0x40 0x5
<7> [44.090914] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 75 31500 640 656 720 840 480 481 484 500 0x40 0xa
<7> [44.090917] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 73 31500 640 664 704 832 480 489 492 520 0x40 0xa
<7> [44.090920] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25200 640 656 752 800 480 490 492 525 0x40 0xa
<7> [44.090922] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa
<6> [44.093984] [IGT] kms_flip: starting subtest plain-flip-ts-check-interruptible
<6> [44.100641] [IGT] kms_flip: starting dynamic subtest A-HDMI-A3
<7> [44.100967] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:292]
<7> [44.101012] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:296]
<7> [44.101539] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [44.101984] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [44.167268] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling AUX_D
<7> [44.169847] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [44.170131] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [44.174030] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [44.174373] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [44.191527] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [44.191821] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [44.195705] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:82:pipe A]
<7> [44.195927] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [44.196129] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [44.196313] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [44.196494] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [44.196685] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [44.196867] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [44.197046] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [44.197227] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [44.197407] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [44.197587] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [44.197773] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [44.197953] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [44.198133] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [44.198313] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [44.198493] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [44.198677] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [44.198858] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [44.199038] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [44.199218] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [44.199398] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [44.199578] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [44.199763] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [44.199943] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [44.200123] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [44.200302] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [44.200482] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [44.200663] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [44.200849] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [44.201030] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [44.201209] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [44.201388] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [44.201568] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [44.201753] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [44.201934] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [44.202113] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [44.202293] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [44.202473] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [44.202654] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:82:pipe A] fastset requirement not met, forcing full modeset
<7> [44.202890] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [44.203062] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:82:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [44.203258] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] ddb ( 0 - 1963) -> ( 0 - 0), size 1963 -> 0
<7> [44.203426] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:77:cursor A] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [44.203594] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32: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> [44.203768] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] lines 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [44.203937] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] blocks 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [44.204105] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] min_ddb 19, 55, 73, 91, 161, 196, 302, 443, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [44.204274] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:82:pipe A] data rate 0 num active planes 0
<7> [44.204457] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 0
<7> [44.204652] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [44.204840] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New voltage level calculated to be logical 0, actual 0
<7> [44.205023] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:82:pipe A] enable: no [modeset]
<7> [44.205204] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:32:plane 1A] fb: [NOFB], visible: no
<7> [44.205385] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:41:plane 2A] fb: [NOFB], visible: no
<7> [44.205566] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:50:plane 3A] fb: [NOFB], visible: no
<7> [44.205751] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:59:plane 4A] fb: [NOFB], visible: no
<7> [44.205931] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:68:plane 5A] fb: [NOFB], visible: no
<7> [44.206112] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:77:cursor A] fb: [NOFB], visible: no
<7> [44.222965] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [44.240346] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [44.240859] i915 0000:03:00.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:32:plane 1A]
<7> [44.241140] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:240:DDI A/PHY A]
<7> [44.241373] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:242:DP-MST A]
<7> [44.241578] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:243:DP-MST B]
<7> [44.241777] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:244:DP-MST C]
<7> [44.241975] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:245:DP-MST D]
<7> [44.242174] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:253:DDI B/PHY B]
<7> [44.242378] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:255:DP-MST A]
<7> [44.242577] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:256:DP-MST B]
<7> [44.242776] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:257:DP-MST C]
<7> [44.242974] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:258:DP-MST D]
<7> [44.243172] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:268:DDI C/PHY C]
<7> [44.243376] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:270:DP-MST A]
<7> [44.243575] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:271:DP-MST B]
<7> [44.243773] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:272:DP-MST C]
<7> [44.243971] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:273:DP-MST D]
<7> [44.244169] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:280:DDI D/PHY D]
<7> [44.244397] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:282:DP-MST A]
<7> [44.244597] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:283:DP-MST B]
<7> [44.244796] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:284:DP-MST C]
<7> [44.244994] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:285:DP-MST D]
<7> [44.245192] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:289:HDMI-A-3]
<7> [44.245492] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [44.245812] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_A
<7> [44.246947] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [44.247239] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:82:pipe A]
<7> [44.247955] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:134:pipe B]
<7> [44.248233] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:186:pipe C]
<7> [44.248363] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:238:pipe D]
<7> [44.248483] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:82:pipe A]
<7> [44.248520] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:289:HDMI-A-3]
<7> [44.248583] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CONNECTOR:289:HDMI-A-3] Limiting display bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [44.248806] i915 0000:03:00.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [44.248999] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:82:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [44.249214] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:280:DDI D/PHY D] [CRTC:82:pipe A]
<7> [44.249533] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [44.249747] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [44.249959] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [44.250171] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [44.250413] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [44.250645] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [44.250875] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [44.251106] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [44.251336] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [44.251573] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [44.251805] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [44.252035] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [44.252265] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [44.252502] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [44.252732] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [44.252963] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [44.253192] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [44.253428] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [44.253659] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [44.253889] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [44.254119] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [44.254348] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [44.254584] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [44.254815] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [44.255045] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [44.255275] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [44.255511] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [44.255742] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [44.255972] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [44.256203] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [44.256438] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [44.256669] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [44.256899] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [44.257131] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [44.257362] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [44.257598] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [44.257829] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [44.258060] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:82:pipe A] fastset requirement not met, forcing full modeset
<7> [44.258310] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [44.258534] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:82:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x1
<7> [44.258781] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [44.258996] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:77:cursor A] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [44.259212] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32: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> [44.259426] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [44.259649] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0
<7> [44.259866] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 55, 73, 91, 161, 196, 302, 443, 31, 0, 0
<7> [44.260083] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:82:pipe A] data rate 594000 num active planes 1
<7> [44.260317] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [44.260556] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [44.260801] i915 0000:03:00.0: [drm:intel_plane_calc_min_cdclk [i915]] [PLANE:32:plane 1A] min cdclk (74250 kHz) > [CRTC:82:pipe A] min cdclk (0 kHz)
<7> [44.261036] i915 0000:03:00.0: [drm:intel_bw_calc_min_cdclk [i915]] new bandwidth min cdclk (11602 kHz) > old min cdclk (0 kHz)
<7> [44.261272] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [44.261511] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New voltage level calculated to be logical 0, actual 0
<7> [44.261745] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:82:pipe A] enable: yes [modeset]
<7> [44.261977] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [44.262210] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [44.262441] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [44.262679] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [44.262911] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [44.263142] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [44.263374] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0
<7> [44.263611] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [44.263843] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, vmin: 0, vmax: 0, pipeline full: 0, guardband: 0 flipline: 0, vmin vblank: 1, vmax vblank: 0
<7> [44.264075] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [44.264308] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [44.264542] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [44.264781] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [44.265014] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [44.265247] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500
<7> [44.265479] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [44.265718] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [44.265950] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [44.266182] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [44.266413] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [44.266656] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [44.266710] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [44.266888] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [44.266972] i915 0000:03:00.0: [drm:gen9_enable_dc5 [i915]] Enabling DC5
<7> [44.267120] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [44.267206] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 01
<7> [44.267352] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [44.267591] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [44.267823] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [44.268055] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [44.268286] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [44.268517] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [44.268755] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [44.268986] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [44.269218] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [44.269450] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:32:plane 1A] fb: [FB:292] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [44.269689] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [44.269921] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [44.270154] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:41:plane 2A] fb: [NOFB], visible: no
<7> [44.270386] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:50:plane 3A] fb: [NOFB], visible: no
<7> [44.270619] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:59:plane 4A] fb: [NOFB], visible: no
<7> [44.270856] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:68:plane 5A] fb: [NOFB], visible: no
<7> [44.271087] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:77:cursor A] fb: [NOFB], visible: no
<7> [44.272346] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [44.272712] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 01 to 00
<7> [44.273133] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [44.273410] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [44.273766] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:240:DDI A/PHY A]
<7> [44.273989] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:242:DP-MST A]
<7> [44.274207] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:243:DP-MST B]
<7> [44.274424] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:244:DP-MST C]
<7> [44.274641] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:245:DP-MST D]
<7> [44.274865] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:253:DDI B/PHY B]
<7> [44.275082] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:255:DP-MST A]
<7> [44.275299] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:256:DP-MST B]
<7> [44.275515] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:257:DP-MST C]
<7> [44.275739] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:258:DP-MST D]
<7> [44.275956] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:268:DDI C/PHY C]
<7> [44.276173] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:270:DP-MST A]
<7> [44.276389] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:271:DP-MST B]
<7> [44.276605] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:272:DP-MST C]
<7> [44.276828] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:273:DP-MST D]
<7> [44.277045] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:280:DDI D/PHY D]
<7> [44.277261] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:282:DP-MST A]
<7> [44.277478] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:283:DP-MST B]
<7> [44.277694] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:284:DP-MST C]
<7> [44.277917] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:285:DP-MST D]
<7> [44.278134] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [44.278686] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [44.279049] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [44.281062] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [44.281291] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:32:plane 1A]
<7> [44.298185] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:289:HDMI-A-3]
<7> [44.298539] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:82:pipe A]
<6> [50.596177] [IGT] kms_flip: finished subtest A-HDMI-A3, FAIL
|