Results for igt@kms_flip@2x-plain-flip-ts-check

shard-bmg-5

IGT-Version: 1.30-g2c9202bdb (x86_64) (Linux: 6.14.0-rc2-xe+ x86_64)

Using IGT_SRANDOM=1739333383 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: 2x-plain-flip-ts-check
Starting dynamic subtest: AB-DP2-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Expected frametime: 16667us; measured 17184.0us +- 1.461us accuracy 0.03%
vblank interval differs from modeline! expected 16666.7us, measured 17184us +- 1.461us, difference 517.3us (354.2 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:1930 run_pair()
  #3 ../tests/kms_flip.c:2087 __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 AB-DP2-HDMI-A3: FAIL (5.086s)
Starting dynamic subtest: AC-DP2-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Expected frametime: 16667us; measured 16936.6us +- 2.308us accuracy 0.04%
vblank interval differs from modeline! expected 16666.7us, measured 16937us +- 2.308us, difference 269.9us (116.9 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:1930 run_pair()
  #3 ../tests/kms_flip.c:2087 __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 AC-DP2-HDMI-A3: FAIL (7.602s)
Starting dynamic subtest: AD-DP2-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Expected frametime: 16667us; measured 16765.1us +- 8.103us accuracy 0.15%
vblank interval differs from modeline! expected 16666.7us, measured 16765us +- 8.103us, difference 98.4us (12.1 sigma)
Dynamic subtest AD-DP2-HDMI-A3: SUCCESS (5.668s)
Starting dynamic subtest: BC-DP2-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Expected frametime: 16667us; measured 16719.7us +- 4.143us accuracy 0.07%
vblank interval differs from modeline! expected 16666.7us, measured 16720us +- 4.143us, difference 53.0us (12.8 sigma)
Dynamic subtest BC-DP2-HDMI-A3: SUCCESS (5.659s)
Starting dynamic subtest: BD-DP2-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Expected frametime: 16667us; measured 16696.1us +- 3.667us accuracy 0.07%
vblank interval differs from modeline! expected 16666.7us, measured 16696us +- 3.667us, difference 29.5us (8.0 sigma)
Dynamic subtest BD-DP2-HDMI-A3: SUCCESS (5.647s)
Starting dynamic subtest: CD-DP2-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Expected frametime: 16667us; measured 16671.5us +- 2.033us accuracy 0.04%
vblank interval differs from modeline! expected 16666.7us, measured 16672us +- 2.033us, difference 4.8us (2.4 sigma)
Dynamic subtest CD-DP2-HDMI-A3: SUCCESS (5.650s)
Subtest 2x-plain-flip-ts-check: FAIL (35.354s)

Starting subtest: 2x-plain-flip-ts-check
Starting dynamic subtest: AB-DP2-HDMI-A3
(kms_flip:7609) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674:
(kms_flip:7609) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon)
Dynamic subtest AB-DP2-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:7609) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_flip:7609) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=7680)
(kms_flip:7609) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:7609) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_flip:7609) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680)
(kms_flip:7609) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:7609) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:7609) intel_allocator_simple-DEBUG: <ial: 0x5ba910086d20, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:7609) intel_allocator_simple-DEBUG: <ial: 0x5ba910086d20, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:7609) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:7609) intel_allocator_simple-DEBUG: <ial: 0x5ba91008ffb0, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:7609) intel_allocator_simple-DEBUG: <ial: 0x5ba91008ffb0, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:7609) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:7609) intel_allocator_simple-DEBUG: <ial: 0x5ba91008ffb0, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:7609) intel_allocator_simple-DEBUG: <ial: 0x5ba91008ffb0, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:7609) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:7609) intel_allocator_simple-DEBUG: <ial: 0x5ba91008ffb0, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:7609) intel_allocator_simple-DEBUG: <ial: 0x5ba91008ffb0, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:7609) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
(kms_flip:7609) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
(kms_flip:7609) DEBUG: No stale events found
(kms_flip:7609) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:7609) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:7609) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:7609) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:7609) INFO: Expected frametime: 16667us; measured 17184.0us +- 1.461us accuracy 0.03%
(kms_flip:7609) INFO: vblank interval differs from modeline! expected 16666.7us, measured 17184us +- 1.461us, difference 517.3us (354.2 sigma)
(kms_flip:7609) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 297.736877
current_received_ts = 297.736389
current_seq = 11656
count = 0
seq_step = 1
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.736877
last_received_ts = 297.736389
last_seq = 11656
current_ts = 297.754059
current_received_ts = 297.753448
current_seq = 11657
count = 1
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.736877/11656, current 297.754059/11657: elapsed=17185.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.754059
last_received_ts = 297.753448
last_seq = 11657
current_ts = 297.771240
current_received_ts = 297.770630
current_seq = 11658
count = 2
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.754059/11657, current 297.771240/11658: elapsed=17183.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.771240
last_received_ts = 297.770630
last_seq = 11658
current_ts = 297.788422
current_received_ts = 297.787811
current_seq = 11659
count = 3
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.771240/11658, current 297.788422/11659: elapsed=17184.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.788422
last_received_ts = 297.787811
last_seq = 11659
current_ts = 297.805603
current_received_ts = 297.804993
current_seq = 11660
count = 4
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.788422/11659, current 297.805603/11660: elapsed=17184.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.805603
last_received_ts = 297.804993
last_seq = 11660
current_ts = 297.822784
current_received_ts = 297.822174
current_seq = 11661
count = 5
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.805603/11660, current 297.822784/11661: elapsed=17184.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.822784
last_received_ts = 297.822174
last_seq = 11661
current_ts = 297.839966
current_received_ts = 297.839355
current_seq = 11662
count = 6
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.822784/11661, current 297.839966/11662: elapsed=17184.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.839966
last_received_ts = 297.839355
last_seq = 11662
current_ts = 297.857147
current_received_ts = 297.856537
current_seq = 11663
count = 7
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.839966/11662, current 297.857147/11663: elapsed=17184.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.857147
last_received_ts = 297.856537
last_seq = 11663
current_ts = 297.874329
current_received_ts = 297.873718
current_seq = 11664
count = 8
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.857147/11663, current 297.874329/11664: elapsed=17185.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.874329
last_received_ts = 297.873718
last_seq = 11664
current_ts = 297.891510
current_received_ts = 297.890900
current_seq = 11665
count = 9
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.874329/11664, current 297.891510/11665: elapsed=17183.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.891510
last_received_ts = 297.890900
last_seq = 11665
current_ts = 297.908722
current_received_ts = 297.908142
current_seq = 11666
count = 10
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.891510/11665, current 297.908722/11666: elapsed=17189.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.908722
last_received_ts = 297.908142
last_seq = 11666
current_ts = 297.925903
current_received_ts = 297.925293
current_seq = 11667
count = 11
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.908722/11666, current 297.925903/11667: elapsed=17180.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.925903
last_received_ts = 297.925293
last_seq = 11667
current_ts = 297.943085
current_received_ts = 297.942474
current_seq = 11668
count = 12
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.925903/11667, current 297.943085/11668: elapsed=17183.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.943085
last_received_ts = 297.942474
last_seq = 11668
current_ts = 297.960266
current_received_ts = 297.959656
current_seq = 11669
count = 13
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.943085/11668, current 297.960266/11669: elapsed=17184.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.960266
last_received_ts = 297.959656
last_seq = 11669
current_ts = 297.977448
current_received_ts = 297.976837
current_seq = 11670
count = 14
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.960266/11669, current 297.977448/11670: elapsed=17185.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.977448
last_received_ts = 297.976837
last_seq = 11670
current_ts = 297.994629
current_received_ts = 297.994019
current_seq = 11671
count = 15
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.977448/11670, current 297.994629/11671: elapsed=17183.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 297.994629
last_received_ts = 297.994019
last_seq = 11671
current_ts = 298.011810
current_received_ts = 298.011200
current_seq = 11672
count = 16
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 297.994629/11671, current 298.011810/11672: elapsed=17184.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.011810
last_received_ts = 298.011200
last_seq = 11672
current_ts = 298.028992
current_received_ts = 298.028381
current_seq = 11673
count = 17
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.011810/11672, current 298.028992/11673: elapsed=17185.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.028992
last_received_ts = 298.028381
last_seq = 11673
current_ts = 298.046173
current_received_ts = 298.045563
current_seq = 11674
count = 18
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.028992/11673, current 298.046173/11674: elapsed=17183.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.046173
last_received_ts = 298.045563
last_seq = 11674
current_ts = 298.063354
current_received_ts = 298.062744
current_seq = 11675
count = 19
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.046173/11674, current 298.063354/11675: elapsed=17184.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.063354
last_received_ts = 298.062744
last_seq = 11675
current_ts = 298.080536
current_received_ts = 298.079926
current_seq = 11676
count = 20
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.063354/11675, current 298.080536/11676: elapsed=17185.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.080536
last_received_ts = 298.079926
last_seq = 11676
current_ts = 298.097748
current_received_ts = 298.097137
current_seq = 11677
count = 21
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.080536/11676, current 298.097748/11677: elapsed=17187.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.097748
last_received_ts = 298.097137
last_seq = 11677
current_ts = 298.114899
current_received_ts = 298.114288
current_seq = 11678
count = 22
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.097748/11677, current 298.114899/11678: elapsed=17180.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.114899
last_received_ts = 298.114288
last_seq = 11678
current_ts = 298.132111
current_received_ts = 298.131500
current_seq = 11679
count = 23
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.114899/11678, current 298.132111/11679: elapsed=17185.0us expected=17184.0us +- 85.9us, error 0.0%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.132111
last_received_ts = 298.131500
last_seq = 11679
current_ts = 298.149231
current_received_ts = 298.148621
current_seq = 11680
count = 24
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.132111/11679, current 298.149231/11680: elapsed=17140.0us expected=17184.0us +- 85.9us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.149231
last_received_ts = 298.148621
last_seq = 11680
current_ts = 298.166351
current_received_ts = 298.165741
current_seq = 11681
count = 25
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.149231/11680, current 298.166351/11681: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.166351
last_received_ts = 298.165741
last_seq = 11681
current_ts = 298.183472
current_received_ts = 298.182861
current_seq = 11682
count = 26
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.166351/11681, current 298.183472/11682: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.183472
last_received_ts = 298.182861
last_seq = 11682
current_ts = 298.200592
current_received_ts = 298.199982
current_seq = 11683
count = 27
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.183472/11682, current 298.200592/11683: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.200592
last_received_ts = 298.199982
last_seq = 11683
current_ts = 298.217712
current_received_ts = 298.217102
current_seq = 11684
count = 28
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.200592/11683, current 298.217712/11684: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.217712
last_received_ts = 298.217102
last_seq = 11684
current_ts = 298.234833
current_received_ts = 298.234222
current_seq = 11685
count = 29
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.217712/11684, current 298.234833/11685: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.234833
last_received_ts = 298.234222
last_seq = 11685
current_ts = 298.251953
current_received_ts = 298.251343
current_seq = 11686
count = 30
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.234833/11685, current 298.251953/11686: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.251953
last_received_ts = 298.251343
last_seq = 11686
current_ts = 298.269073
current_received_ts = 298.268463
current_seq = 11687
count = 31
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.251953/11686, current 298.269073/11687: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.269073
last_received_ts = 298.268463
last_seq = 11687
current_ts = 298.286194
current_received_ts = 298.285583
current_seq = 11688
count = 32
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.269073/11687, current 298.286194/11688: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.286194
last_received_ts = 298.285583
last_seq = 11688
current_ts = 298.303314
current_received_ts = 298.302704
current_seq = 11689
count = 33
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.286194/11688, current 298.303314/11689: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.303314
last_received_ts = 298.302704
last_seq = 11689
current_ts = 298.320435
current_received_ts = 298.319855
current_seq = 11690
count = 34
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.303314/11689, current 298.320435/11690: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.320435
last_received_ts = 298.319855
last_seq = 11690
current_ts = 298.337555
current_received_ts = 298.337128
current_seq = 11691
count = 35
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.320435/11690, current 298.337555/11691: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.337555
last_received_ts = 298.337128
last_seq = 11691
current_ts = 298.354675
current_received_ts = 298.354218
current_seq = 11692
count = 36
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.337555/11691, current 298.354675/11692: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.354675
last_received_ts = 298.354218
last_seq = 11692
current_ts = 298.371796
current_received_ts = 298.371246
current_seq = 11693
count = 37
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.354675/11692, current 298.371796/11693: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.371796
last_received_ts = 298.371246
last_seq = 11693
current_ts = 298.388916
current_received_ts = 298.388336
current_seq = 11694
count = 38
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.371796/11693, current 298.388916/11694: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.388916
last_received_ts = 298.388336
last_seq = 11694
current_ts = 298.406036
current_received_ts = 298.405426
current_seq = 11695
count = 39
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.388916/11694, current 298.406036/11695: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.406036
last_received_ts = 298.405426
last_seq = 11695
current_ts = 298.423157
current_received_ts = 298.422546
current_seq = 11696
count = 40
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.406036/11695, current 298.423157/11696: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.423157
last_received_ts = 298.422546
last_seq = 11696
current_ts = 298.440277
current_received_ts = 298.439667
current_seq = 11697
count = 41
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.423157/11696, current 298.440277/11697: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.440277
last_received_ts = 298.439667
last_seq = 11697
current_ts = 298.457397
current_received_ts = 298.456818
current_seq = 11698
count = 42
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.440277/11697, current 298.457397/11698: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.457397
last_received_ts = 298.456818
last_seq = 11698
current_ts = 298.474518
current_received_ts = 298.473938
current_seq = 11699
count = 43
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.457397/11698, current 298.474518/11699: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.474518
last_received_ts = 298.473938
last_seq = 11699
current_ts = 298.491638
current_received_ts = 298.491058
current_seq = 11700
count = 44
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.474518/11699, current 298.491638/11700: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.491638
last_received_ts = 298.491058
last_seq = 11700
current_ts = 298.508759
current_received_ts = 298.508148
current_seq = 11701
count = 45
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.491638/11700, current 298.508759/11701: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.508759
last_received_ts = 298.508148
last_seq = 11701
current_ts = 298.525879
current_received_ts = 298.525269
current_seq = 11702
count = 46
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.508759/11701, current 298.525879/11702: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.525879
last_received_ts = 298.525269
last_seq = 11702
current_ts = 298.542999
current_received_ts = 298.542389
current_seq = 11703
count = 47
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.525879/11702, current 298.542999/11703: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.542999
last_received_ts = 298.542389
last_seq = 11703
current_ts = 298.560120
current_received_ts = 298.559509
current_seq = 11704
count = 48
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.542999/11703, current 298.560120/11704: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.560120
last_received_ts = 298.559509
last_seq = 11704
current_ts = 298.577240
current_received_ts = 298.576630
current_seq = 11705
count = 49
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.560120/11704, current 298.577240/11705: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.577240
last_received_ts = 298.576630
last_seq = 11705
current_ts = 298.594360
current_received_ts = 298.593781
current_seq = 11706
count = 50
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.577240/11705, current 298.594360/11706: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.594360
last_received_ts = 298.593781
last_seq = 11706
current_ts = 298.611481
current_received_ts = 298.610901
current_seq = 11707
count = 51
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.594360/11706, current 298.611481/11707: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.611481
last_received_ts = 298.610901
last_seq = 11707
current_ts = 298.628601
current_received_ts = 298.627991
current_seq = 11708
count = 52
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.611481/11707, current 298.628601/11708: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.628601
last_received_ts = 298.627991
last_seq = 11708
current_ts = 298.645721
current_received_ts = 298.645111
current_seq = 11709
count = 53
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.628601/11708, current 298.645721/11709: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.645721
last_received_ts = 298.645111
last_seq = 11709
current_ts = 298.662842
current_received_ts = 298.662231
current_seq = 11710
count = 54
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.645721/11709, current 298.662842/11710: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.662842
last_received_ts = 298.662231
last_seq = 11710
current_ts = 298.679962
current_received_ts = 298.679352
current_seq = 11711
count = 55
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.662842/11710, current 298.679962/11711: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.679962
last_received_ts = 298.679352
last_seq = 11711
current_ts = 298.697083
current_received_ts = 298.696472
current_seq = 11712
count = 56
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.679962/11711, current 298.697083/11712: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.697083
last_received_ts = 298.696472
last_seq = 11712
current_ts = 298.714203
current_received_ts = 298.713593
current_seq = 11713
count = 57
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.697083/11712, current 298.714203/11713: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.714203
last_received_ts = 298.713593
last_seq = 11713
current_ts = 298.731323
current_received_ts = 298.730713
current_seq = 11714
count = 58
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.714203/11713, current 298.731323/11714: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.731323
last_received_ts = 298.730713
last_seq = 11714
current_ts = 298.748444
current_received_ts = 298.747864
current_seq = 11715
count = 59
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.731323/11714, current 298.748444/11715: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.748444
last_received_ts = 298.747864
last_seq = 11715
current_ts = 298.765564
current_received_ts = 298.764984
current_seq = 11716
count = 60
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.748444/11715, current 298.765564/11716: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.765564
last_received_ts = 298.764984
last_seq = 11716
current_ts = 298.782715
current_received_ts = 298.782104
current_seq = 11717
count = 61
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.765564/11716, current 298.782715/11717: elapsed=17127.0us expected=17184.0us +- 85.9us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.782715
last_received_ts = 298.782104
last_seq = 11717
current_ts = 298.799805
current_received_ts = 298.799225
current_seq = 11718
count = 62
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.782715/11717, current 298.799805/11718: elapsed=17115.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.799805
last_received_ts = 298.799225
last_seq = 11718
current_ts = 298.816925
current_received_ts = 298.816315
current_seq = 11719
count = 63
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.799805/11718, current 298.816925/11719: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.816925
last_received_ts = 298.816315
last_seq = 11719
current_ts = 298.834045
current_received_ts = 298.833435
current_seq = 11720
count = 64
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.816925/11719, current 298.834045/11720: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.834045
last_received_ts = 298.833435
last_seq = 11720
current_ts = 298.851166
current_received_ts = 298.850555
current_seq = 11721
count = 65
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.834045/11720, current 298.851166/11721: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.851166
last_received_ts = 298.850555
last_seq = 11721
current_ts = 298.868286
current_received_ts = 298.867676
current_seq = 11722
count = 66
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.851166/11721, current 298.868286/11722: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.868286
last_received_ts = 298.867676
last_seq = 11722
current_ts = 298.885406
current_received_ts = 298.884796
current_seq = 11723
count = 67
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.868286/11722, current 298.885406/11723: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.885406
last_received_ts = 298.884796
last_seq = 11723
current_ts = 298.902527
current_received_ts = 298.901917
current_seq = 11724
count = 68
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.885406/11723, current 298.902527/11724: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.902527
last_received_ts = 298.901917
last_seq = 11724
current_ts = 298.919647
current_received_ts = 298.919067
current_seq = 11725
count = 69
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.902527/11724, current 298.919647/11725: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.919647
last_received_ts = 298.919067
last_seq = 11725
current_ts = 298.936798
current_received_ts = 298.936157
current_seq = 11726
count = 70
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.919647/11725, current 298.936798/11726: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.936798
last_received_ts = 298.936157
last_seq = 11726
current_ts = 298.953888
current_received_ts = 298.953278
current_seq = 11727
count = 71
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.936798/11726, current 298.953888/11727: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.953888
last_received_ts = 298.953278
last_seq = 11727
current_ts = 298.971008
current_received_ts = 298.970398
current_seq = 11728
count = 72
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.953888/11727, current 298.971008/11728: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.971008
last_received_ts = 298.970398
last_seq = 11728
current_ts = 298.988159
current_received_ts = 298.987518
current_seq = 11729
count = 73
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.971008/11728, current 298.988159/11729: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 298.988159
last_received_ts = 298.987518
last_seq = 11729
current_ts = 299.005249
current_received_ts = 299.004639
current_seq = 11730
count = 74
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 298.988159/11729, current 299.005249/11730: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.005249
last_received_ts = 299.004639
last_seq = 11730
current_ts = 299.022400
current_received_ts = 299.021759
current_seq = 11731
count = 75
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.005249/11730, current 299.022400/11731: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.022400
last_received_ts = 299.021759
last_seq = 11731
current_ts = 299.039520
current_received_ts = 299.038879
current_seq = 11732
count = 76
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.022400/11731, current 299.039520/11732: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.039520
last_received_ts = 299.038879
last_seq = 11732
current_ts = 299.056641
current_received_ts = 299.056000
current_seq = 11733
count = 77
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.039520/11732, current 299.056641/11733: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.056641
last_received_ts = 299.056000
last_seq = 11733
current_ts = 299.073761
current_received_ts = 299.073151
current_seq = 11734
count = 78
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.056641/11733, current 299.073761/11734: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.073761
last_received_ts = 299.073151
last_seq = 11734
current_ts = 299.090881
current_received_ts = 299.090240
current_seq = 11735
count = 79
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.073761/11734, current 299.090881/11735: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.090881
last_received_ts = 299.090240
last_seq = 11735
current_ts = 299.108002
current_received_ts = 299.107361
current_seq = 11736
count = 80
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.090881/11735, current 299.108002/11736: elapsed=17120.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.108002
last_received_ts = 299.107361
last_seq = 11736
current_ts = 299.125122
current_received_ts = 299.124481
current_seq = 11737
count = 81
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.108002/11736, current 299.125122/11737: elapsed=17121.0us expected=17184.0us +- 85.9us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.125122
last_received_ts = 299.124481
last_seq = 11737
current_ts = 299.142212
current_received_ts = 299.141602
current_seq = 11738
count = 82
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.125122/11737, current 299.142212/11738: elapsed=17106.0us expected=17184.0us +- 85.9us, error 0.5%
(kms_flip:7609) DEBUG: name = flip
last_ts = 299.142212
last_received_ts = 299.141602
last_seq = 11738
current_ts = 299.159271
current_received_ts = 299.158661
current_seq = 11739
count = 83
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 299.142212/11738, current 299.159271/11739: elapsed=17064.0us expected=17184.0us +- 85.9us, error 0.7%
(kms_flip:7609) DEBUG: inconsistent flip ts/seq: last 299.142212/11738, current 299.159271/11739: elapsed=17064.0us expected=17184.0us
(kms_flip:7609) DEBUG: expected 106879, counted 83, encoder type 2
(kms_flip:7609) DEBUG: dropped frames, expected 106879, counted 83, encoder type 2
(kms_flip:7609) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674:
(kms_flip:7609) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon)
(kms_flip:7609) igt_core-INFO: Stack trace:
(kms_flip:7609) igt_core-INFO:   #0 ../lib/igt_core.c:2051 __igt_fail_assert()
(kms_flip:7609) igt_core-INFO:   #1 ../tests/kms_flip.c:791 run_test_on_crtc_set.constprop.0()
(kms_flip:7609) igt_core-INFO:   #2 ../tests/kms_flip.c:1930 run_pair()
(kms_flip:7609) igt_core-INFO:   #3 ../tests/kms_flip.c:2087 __igt_unique____real_main2001()
(kms_flip:7609) igt_core-INFO:   #4 ../tests/kms_flip.c:2001 main()
(kms_flip:7609) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:7609) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:7609) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest AB-DP2-HDMI-A3: FAIL (5.086s)
Starting dynamic subtest: AC-DP2-HDMI-A3
(kms_flip:7609) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674:
(kms_flip:7609) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon)
Dynamic subtest AC-DP2-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:7609) DEBUG: flip ts/seq: last 303.130951/11966, current 303.147888/11967: elapsed=16918.0us expected=16936.6us +- 84.7us, error 0.1%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.147888
last_received_ts = 303.147278
last_seq = 11967
current_ts = 303.164795
current_received_ts = 303.164185
current_seq = 11968
count = 17
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.147888/11967, current 303.164795/11968: elapsed=16905.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.164795
last_received_ts = 303.164185
last_seq = 11968
current_ts = 303.181702
current_received_ts = 303.181091
current_seq = 11969
count = 18
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.164795/11968, current 303.181702/11969: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.181702
last_received_ts = 303.181091
last_seq = 11969
current_ts = 303.198578
current_received_ts = 303.197998
current_seq = 11970
count = 19
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.181702/11969, current 303.198578/11970: elapsed=16903.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.198578
last_received_ts = 303.197998
last_seq = 11970
current_ts = 303.215515
current_received_ts = 303.214966
current_seq = 11971
count = 20
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.198578/11970, current 303.215515/11971: elapsed=16913.0us expected=16936.6us +- 84.7us, error 0.1%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.215515
last_received_ts = 303.214966
last_seq = 11971
current_ts = 303.232391
current_received_ts = 303.231812
current_seq = 11972
count = 21
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.215515/11971, current 303.232391/11972: elapsed=16891.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.232391
last_received_ts = 303.231812
last_seq = 11972
current_ts = 303.249298
current_received_ts = 303.248779
current_seq = 11973
count = 22
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.232391/11972, current 303.249298/11973: elapsed=16914.0us expected=16936.6us +- 84.7us, error 0.1%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.249298
last_received_ts = 303.248779
last_seq = 11973
current_ts = 303.266205
current_received_ts = 303.265656
current_seq = 11974
count = 23
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.249298/11973, current 303.266205/11974: elapsed=16894.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.266205
last_received_ts = 303.265656
last_seq = 11974
current_ts = 303.283112
current_received_ts = 303.282562
current_seq = 11975
count = 24
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.266205/11974, current 303.283112/11975: elapsed=16908.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.283112
last_received_ts = 303.282562
last_seq = 11975
current_ts = 303.300018
current_received_ts = 303.299469
current_seq = 11976
count = 25
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.283112/11975, current 303.300018/11976: elapsed=16913.0us expected=16936.6us +- 84.7us, error 0.1%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.300018
last_received_ts = 303.299469
last_seq = 11976
current_ts = 303.316925
current_received_ts = 303.316376
current_seq = 11977
count = 26
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.300018/11976, current 303.316925/11977: elapsed=16895.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.316925
last_received_ts = 303.316376
last_seq = 11977
current_ts = 303.333832
current_received_ts = 303.333282
current_seq = 11978
count = 27
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.316925/11977, current 303.333832/11978: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.333832
last_received_ts = 303.333282
last_seq = 11978
current_ts = 303.350708
current_received_ts = 303.350128
current_seq = 11979
count = 28
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.333832/11978, current 303.350708/11979: elapsed=16900.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.350708
last_received_ts = 303.350128
last_seq = 11979
current_ts = 303.367645
current_received_ts = 303.367096
current_seq = 11980
count = 29
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.350708/11979, current 303.367645/11980: elapsed=16909.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.367645
last_received_ts = 303.367096
last_seq = 11980
current_ts = 303.384521
current_received_ts = 303.383942
current_seq = 11981
count = 30
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.367645/11980, current 303.384521/11981: elapsed=16903.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.384521
last_received_ts = 303.383942
last_seq = 11981
current_ts = 303.401428
current_received_ts = 303.400848
current_seq = 11982
count = 31
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.384521/11981, current 303.401428/11982: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.401428
last_received_ts = 303.400848
last_seq = 11982
current_ts = 303.418335
current_received_ts = 303.417725
current_seq = 11983
count = 32
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.401428/11982, current 303.418335/11983: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.418335
last_received_ts = 303.417725
last_seq = 11983
current_ts = 303.435242
current_received_ts = 303.434662
current_seq = 11984
count = 33
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.418335/11983, current 303.435242/11984: elapsed=16903.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.435242
last_received_ts = 303.434662
last_seq = 11984
current_ts = 303.452148
current_received_ts = 303.451538
current_seq = 11985
count = 34
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.435242/11984, current 303.452148/11985: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.452148
last_received_ts = 303.451538
last_seq = 11985
current_ts = 303.469055
current_received_ts = 303.468445
current_seq = 11986
count = 35
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.452148/11985, current 303.469055/11986: elapsed=16905.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.469055
last_received_ts = 303.468445
last_seq = 11986
current_ts = 303.485962
current_received_ts = 303.485352
current_seq = 11987
count = 36
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.469055/11986, current 303.485962/11987: elapsed=16903.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.485962
last_received_ts = 303.485352
last_seq = 11987
current_ts = 303.502869
current_received_ts = 303.502258
current_seq = 11988
count = 37
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.485962/11987, current 303.502869/11988: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.502869
last_received_ts = 303.502258
last_seq = 11988
current_ts = 303.519775
current_received_ts = 303.519165
current_seq = 11989
count = 38
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.502869/11988, current 303.519775/11989: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.519775
last_received_ts = 303.519165
last_seq = 11989
current_ts = 303.536682
current_received_ts = 303.536255
current_seq = 11990
count = 39
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.519775/11989, current 303.536682/11990: elapsed=16913.0us expected=16936.6us +- 84.7us, error 0.1%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.536682
last_received_ts = 303.536255
last_seq = 11990
current_ts = 303.553589
current_received_ts = 303.553131
current_seq = 11991
count = 40
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.536682/11990, current 303.553589/11991: elapsed=16901.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.553589
last_received_ts = 303.553131
last_seq = 11991
current_ts = 303.570496
current_received_ts = 303.569977
current_seq = 11992
count = 41
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.553589/11991, current 303.570496/11992: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.570496
last_received_ts = 303.569977
last_seq = 11992
current_ts = 303.587372
current_received_ts = 303.586761
current_seq = 11993
count = 42
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.570496/11992, current 303.587372/11993: elapsed=16895.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.587372
last_received_ts = 303.586761
last_seq = 11993
current_ts = 303.604279
current_received_ts = 303.603668
current_seq = 11994
count = 43
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.587372/11993, current 303.604279/11994: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.604279
last_received_ts = 303.603668
last_seq = 11994
current_ts = 303.621185
current_received_ts = 303.620544
current_seq = 11995
count = 44
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.604279/11994, current 303.621185/11995: elapsed=16901.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.621185
last_received_ts = 303.620544
last_seq = 11995
current_ts = 303.638092
current_received_ts = 303.637451
current_seq = 11996
count = 45
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.621185/11995, current 303.638092/11996: elapsed=16905.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.638092
last_received_ts = 303.637451
last_seq = 11996
current_ts = 303.654999
current_received_ts = 303.654358
current_seq = 11997
count = 46
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.638092/11996, current 303.654999/11997: elapsed=16918.0us expected=16936.6us +- 84.7us, error 0.1%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.654999
last_received_ts = 303.654358
last_seq = 11997
current_ts = 303.671906
current_received_ts = 303.671265
current_seq = 11998
count = 47
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.654999/11997, current 303.671906/11998: elapsed=16890.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.671906
last_received_ts = 303.671265
last_seq = 11998
current_ts = 303.688812
current_received_ts = 303.688171
current_seq = 11999
count = 48
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.671906/11998, current 303.688812/11999: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.688812
last_received_ts = 303.688171
last_seq = 11999
current_ts = 303.705719
current_received_ts = 303.705078
current_seq = 12000
count = 49
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.688812/11999, current 303.705719/12000: elapsed=16903.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.705719
last_received_ts = 303.705078
last_seq = 12000
current_ts = 303.722626
current_received_ts = 303.721985
current_seq = 12001
count = 50
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.705719/12000, current 303.722626/12001: elapsed=16907.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.722626
last_received_ts = 303.721985
last_seq = 12001
current_ts = 303.739502
current_received_ts = 303.738892
current_seq = 12002
count = 51
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.722626/12001, current 303.739502/12002: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.739502
last_received_ts = 303.738892
last_seq = 12002
current_ts = 303.756409
current_received_ts = 303.755829
current_seq = 12003
count = 52
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.739502/12002, current 303.756409/12003: elapsed=16907.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.756409
last_received_ts = 303.755829
last_seq = 12003
current_ts = 303.773315
current_received_ts = 303.772736
current_seq = 12004
count = 53
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.756409/12003, current 303.773315/12004: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.773315
last_received_ts = 303.772736
last_seq = 12004
current_ts = 303.790222
current_received_ts = 303.789642
current_seq = 12005
count = 54
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.773315/12004, current 303.790222/12005: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.790222
last_received_ts = 303.789642
last_seq = 12005
current_ts = 303.807129
current_received_ts = 303.806519
current_seq = 12006
count = 55
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.790222/12005, current 303.807129/12006: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.807129
last_received_ts = 303.806519
last_seq = 12006
current_ts = 303.824036
current_received_ts = 303.823425
current_seq = 12007
count = 56
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.807129/12006, current 303.824036/12007: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.824036
last_received_ts = 303.823425
last_seq = 12007
current_ts = 303.840942
current_received_ts = 303.840424
current_seq = 12008
count = 57
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.824036/12007, current 303.840942/12008: elapsed=16900.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.840942
last_received_ts = 303.840424
last_seq = 12008
current_ts = 303.857849
current_received_ts = 303.857300
current_seq = 12009
count = 58
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.840942/12008, current 303.857849/12009: elapsed=16917.0us expected=16936.6us +- 84.7us, error 0.1%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.857849
last_received_ts = 303.857300
last_seq = 12009
current_ts = 303.874756
current_received_ts = 303.874237
current_seq = 12010
count = 59
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.857849/12009, current 303.874756/12010: elapsed=16902.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.874756
last_received_ts = 303.874237
last_seq = 12010
current_ts = 303.891663
current_received_ts = 303.891144
current_seq = 12011
count = 60
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.874756/12010, current 303.891663/12011: elapsed=16902.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.891663
last_received_ts = 303.891144
last_seq = 12011
current_ts = 303.908569
current_received_ts = 303.908081
current_seq = 12012
count = 61
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.891663/12011, current 303.908569/12012: elapsed=16899.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.908569
last_received_ts = 303.908081
last_seq = 12012
current_ts = 303.925476
current_received_ts = 303.924927
current_seq = 12013
count = 62
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.908569/12012, current 303.925476/12013: elapsed=16906.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.925476
last_received_ts = 303.924927
last_seq = 12013
current_ts = 303.942383
current_received_ts = 303.941772
current_seq = 12014
count = 63
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.925476/12013, current 303.942383/12014: elapsed=16906.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.942383
last_received_ts = 303.941772
last_seq = 12014
current_ts = 303.959259
current_received_ts = 303.958679
current_seq = 12015
count = 64
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.942383/12014, current 303.959259/12015: elapsed=16900.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.959259
last_received_ts = 303.958679
last_seq = 12015
current_ts = 303.976166
current_received_ts = 303.975586
current_seq = 12016
count = 65
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.959259/12015, current 303.976166/12016: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.976166
last_received_ts = 303.975586
last_seq = 12016
current_ts = 303.993073
current_received_ts = 303.992462
current_seq = 12017
count = 66
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.976166/12016, current 303.993073/12017: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 303.993073
last_received_ts = 303.992462
last_seq = 12017
current_ts = 304.009979
current_received_ts = 304.009369
current_seq = 12018
count = 67
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 303.993073/12017, current 304.009979/12018: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.009979
last_received_ts = 304.009369
last_seq = 12018
current_ts = 304.026886
current_received_ts = 304.026306
current_seq = 12019
count = 68
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.009979/12018, current 304.026886/12019: elapsed=16903.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.026886
last_received_ts = 304.026306
last_seq = 12019
current_ts = 304.043793
current_received_ts = 304.043182
current_seq = 12020
count = 69
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.026886/12019, current 304.043793/12020: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.043793
last_received_ts = 304.043182
last_seq = 12020
current_ts = 304.060699
current_received_ts = 304.060089
current_seq = 12021
count = 70
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.043793/12020, current 304.060699/12021: elapsed=16907.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.060699
last_received_ts = 304.060089
last_seq = 12021
current_ts = 304.077606
current_received_ts = 304.076996
current_seq = 12022
count = 71
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.060699/12021, current 304.077606/12022: elapsed=16901.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.077606
last_received_ts = 304.076996
last_seq = 12022
current_ts = 304.094513
current_received_ts = 304.093903
current_seq = 12023
count = 72
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.077606/12022, current 304.094513/12023: elapsed=16905.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.094513
last_received_ts = 304.093903
last_seq = 12023
current_ts = 304.111420
current_received_ts = 304.110901
current_seq = 12024
count = 73
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.094513/12023, current 304.111420/12024: elapsed=16904.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.111420
last_received_ts = 304.110901
last_seq = 12024
current_ts = 304.128326
current_received_ts = 304.127777
current_seq = 12025
count = 74
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.111420/12024, current 304.128326/12025: elapsed=16906.0us expected=16936.6us +- 84.7us, error 0.2%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.128326
last_received_ts = 304.127777
last_seq = 12025
current_ts = 304.145203
current_received_ts = 304.144562
current_seq = 12026
count = 75
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.128326/12025, current 304.145203/12026: elapsed=16885.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.145203
last_received_ts = 304.144562
last_seq = 12026
current_ts = 304.162079
current_received_ts = 304.161469
current_seq = 12027
count = 76
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.145203/12026, current 304.162079/12027: elapsed=16880.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.162079
last_received_ts = 304.161469
last_seq = 12027
current_ts = 304.178955
current_received_ts = 304.178345
current_seq = 12028
count = 77
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.162079/12027, current 304.178955/12028: elapsed=16875.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.178955
last_received_ts = 304.178345
last_seq = 12028
current_ts = 304.195831
current_received_ts = 304.195221
current_seq = 12029
count = 78
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.178955/12028, current 304.195831/12029: elapsed=16875.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.195831
last_received_ts = 304.195221
last_seq = 12029
current_ts = 304.212708
current_received_ts = 304.212219
current_seq = 12030
count = 79
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.195831/12029, current 304.212708/12030: elapsed=16877.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.212708
last_received_ts = 304.212219
last_seq = 12030
current_ts = 304.229584
current_received_ts = 304.229095
current_seq = 12031
count = 80
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.212708/12030, current 304.229584/12031: elapsed=16883.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.229584
last_received_ts = 304.229095
last_seq = 12031
current_ts = 304.246460
current_received_ts = 304.245941
current_seq = 12032
count = 81
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.229584/12031, current 304.246460/12032: elapsed=16875.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.246460
last_received_ts = 304.245941
last_seq = 12032
current_ts = 304.263336
current_received_ts = 304.262787
current_seq = 12033
count = 82
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.246460/12032, current 304.263336/12033: elapsed=16865.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.263336
last_received_ts = 304.262787
last_seq = 12033
current_ts = 304.280212
current_received_ts = 304.279694
current_seq = 12034
count = 83
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.263336/12033, current 304.280212/12034: elapsed=16883.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.280212
last_received_ts = 304.279694
last_seq = 12034
current_ts = 304.297089
current_received_ts = 304.296570
current_seq = 12035
count = 84
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.280212/12034, current 304.297089/12035: elapsed=16879.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.297089
last_received_ts = 304.296570
last_seq = 12035
current_ts = 304.313965
current_received_ts = 304.313446
current_seq = 12036
count = 85
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.297089/12035, current 304.313965/12036: elapsed=16871.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.313965
last_received_ts = 304.313446
last_seq = 12036
current_ts = 304.330841
current_received_ts = 304.330322
current_seq = 12037
count = 86
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.313965/12036, current 304.330841/12037: elapsed=16878.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.330841
last_received_ts = 304.330322
last_seq = 12037
current_ts = 304.347717
current_received_ts = 304.347168
current_seq = 12038
count = 87
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.330841/12037, current 304.347717/12038: elapsed=16873.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.347717
last_received_ts = 304.347168
last_seq = 12038
current_ts = 304.364563
current_received_ts = 304.364105
current_seq = 12039
count = 88
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.347717/12038, current 304.364563/12039: elapsed=16866.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.364563
last_received_ts = 304.364105
last_seq = 12039
current_ts = 304.381470
current_received_ts = 304.380951
current_seq = 12040
count = 89
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.364563/12039, current 304.381470/12040: elapsed=16883.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.381470
last_received_ts = 304.380951
last_seq = 12040
current_ts = 304.398346
current_received_ts = 304.397827
current_seq = 12041
count = 90
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.381470/12040, current 304.398346/12041: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.398346
last_received_ts = 304.397827
last_seq = 12041
current_ts = 304.415222
current_received_ts = 304.414612
current_seq = 12042
count = 91
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.398346/12041, current 304.415222/12042: elapsed=16878.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.415222
last_received_ts = 304.414612
last_seq = 12042
current_ts = 304.432098
current_received_ts = 304.431488
current_seq = 12043
count = 92
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.415222/12042, current 304.432098/12043: elapsed=16870.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.432098
last_received_ts = 304.431488
last_seq = 12043
current_ts = 304.448975
current_received_ts = 304.448425
current_seq = 12044
count = 93
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.432098/12043, current 304.448975/12044: elapsed=16882.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.448975
last_received_ts = 304.448425
last_seq = 12044
current_ts = 304.465820
current_received_ts = 304.465302
current_seq = 12045
count = 94
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.448975/12044, current 304.465820/12045: elapsed=16868.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.465820
last_received_ts = 304.465302
last_seq = 12045
current_ts = 304.482697
current_received_ts = 304.482178
current_seq = 12046
count = 95
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.465820/12045, current 304.482697/12046: elapsed=16871.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.482697
last_received_ts = 304.482178
last_seq = 12046
current_ts = 304.499603
current_received_ts = 304.499084
current_seq = 12047
count = 96
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.482697/12046, current 304.499603/12047: elapsed=16891.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.499603
last_received_ts = 304.499084
last_seq = 12047
current_ts = 304.516479
current_received_ts = 304.515930
current_seq = 12048
count = 97
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.499603/12047, current 304.516479/12048: elapsed=16872.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.516479
last_received_ts = 304.515930
last_seq = 12048
current_ts = 304.533356
current_received_ts = 304.532806
current_seq = 12049
count = 98
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.516479/12048, current 304.533356/12049: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.533356
last_received_ts = 304.532806
last_seq = 12049
current_ts = 304.550201
current_received_ts = 304.549683
current_seq = 12050
count = 99
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.533356/12049, current 304.550201/12050: elapsed=16867.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.550201
last_received_ts = 304.549683
last_seq = 12050
current_ts = 304.567078
current_received_ts = 304.566589
current_seq = 12051
count = 100
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.550201/12050, current 304.567078/12051: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.567078
last_received_ts = 304.566589
last_seq = 12051
current_ts = 304.583984
current_received_ts = 304.583435
current_seq = 12052
count = 101
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.567078/12051, current 304.583984/12052: elapsed=16885.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.583984
last_received_ts = 304.583435
last_seq = 12052
current_ts = 304.600861
current_received_ts = 304.600311
current_seq = 12053
count = 102
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.583984/12052, current 304.600861/12053: elapsed=16874.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.600861
last_received_ts = 304.600311
last_seq = 12053
current_ts = 304.617706
current_received_ts = 304.617126
current_seq = 12054
count = 103
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.600861/12053, current 304.617706/12054: elapsed=16873.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.617706
last_received_ts = 304.617126
last_seq = 12054
current_ts = 304.634583
current_received_ts = 304.634003
current_seq = 12055
count = 104
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.617706/12054, current 304.634583/12055: elapsed=16872.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.634583
last_received_ts = 304.634003
last_seq = 12055
current_ts = 304.651459
current_received_ts = 304.650848
current_seq = 12056
count = 105
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.634583/12055, current 304.651459/12056: elapsed=16874.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.651459
last_received_ts = 304.650848
last_seq = 12056
current_ts = 304.668335
current_received_ts = 304.667725
current_seq = 12057
count = 106
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.651459/12056, current 304.668335/12057: elapsed=16875.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.668335
last_received_ts = 304.667725
last_seq = 12057
current_ts = 304.685211
current_received_ts = 304.684601
current_seq = 12058
count = 107
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.668335/12057, current 304.685211/12058: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.685211
last_received_ts = 304.684601
last_seq = 12058
current_ts = 304.702087
current_received_ts = 304.701477
current_seq = 12059
count = 108
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.685211/12058, current 304.702087/12059: elapsed=16874.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.702087
last_received_ts = 304.701477
last_seq = 12059
current_ts = 304.718964
current_received_ts = 304.718353
current_seq = 12060
count = 109
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.702087/12059, current 304.718964/12060: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.718964
last_received_ts = 304.718353
last_seq = 12060
current_ts = 304.735840
current_received_ts = 304.735260
current_seq = 12061
count = 110
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.718964/12060, current 304.735840/12061: elapsed=16879.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.735840
last_received_ts = 304.735260
last_seq = 12061
current_ts = 304.752716
current_received_ts = 304.752106
current_seq = 12062
count = 111
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.735840/12061, current 304.752716/12062: elapsed=16873.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.752716
last_received_ts = 304.752106
last_seq = 12062
current_ts = 304.769592
current_received_ts = 304.768982
current_seq = 12063
count = 112
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.752716/12062, current 304.769592/12063: elapsed=16875.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.769592
last_received_ts = 304.768982
last_seq = 12063
current_ts = 304.786469
current_received_ts = 304.785858
current_seq = 12064
count = 113
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.769592/12063, current 304.786469/12064: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.786469
last_received_ts = 304.785858
last_seq = 12064
current_ts = 304.803345
current_received_ts = 304.802795
current_seq = 12065
count = 114
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.786469/12064, current 304.803345/12065: elapsed=16882.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.803345
last_received_ts = 304.802795
last_seq = 12065
current_ts = 304.820221
current_received_ts = 304.819672
current_seq = 12066
count = 115
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.803345/12065, current 304.820221/12066: elapsed=16875.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.820221
last_received_ts = 304.819672
last_seq = 12066
current_ts = 304.837097
current_received_ts = 304.836609
current_seq = 12067
count = 116
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.820221/12066, current 304.837097/12067: elapsed=16877.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.837097
last_received_ts = 304.836609
last_seq = 12067
current_ts = 304.853973
current_received_ts = 304.853455
current_seq = 12068
count = 117
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.837097/12067, current 304.853973/12068: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.853973
last_received_ts = 304.853455
last_seq = 12068
current_ts = 304.870850
current_received_ts = 304.870331
current_seq = 12069
count = 118
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.853973/12068, current 304.870850/12069: elapsed=16871.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.870850
last_received_ts = 304.870331
last_seq = 12069
current_ts = 304.887726
current_received_ts = 304.887177
current_seq = 12070
count = 119
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.870850/12069, current 304.887726/12070: elapsed=16879.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.887726
last_received_ts = 304.887177
last_seq = 12070
current_ts = 304.904602
current_received_ts = 304.904083
current_seq = 12071
count = 120
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.887726/12070, current 304.904602/12071: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.904602
last_received_ts = 304.904083
last_seq = 12071
current_ts = 304.921478
current_received_ts = 304.920929
current_seq = 12072
count = 121
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.904602/12071, current 304.921478/12072: elapsed=16871.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.921478
last_received_ts = 304.920929
last_seq = 12072
current_ts = 304.938354
current_received_ts = 304.937805
current_seq = 12073
count = 122
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.921478/12072, current 304.938354/12073: elapsed=16875.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.938354
last_received_ts = 304.937805
last_seq = 12073
current_ts = 304.955231
current_received_ts = 304.954681
current_seq = 12074
count = 123
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.938354/12073, current 304.955231/12074: elapsed=16868.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.955231
last_received_ts = 304.954681
last_seq = 12074
current_ts = 304.972107
current_received_ts = 304.971558
current_seq = 12075
count = 124
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.955231/12074, current 304.972107/12075: elapsed=16884.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.972107
last_received_ts = 304.971558
last_seq = 12075
current_ts = 304.988983
current_received_ts = 304.988434
current_seq = 12076
count = 125
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.972107/12075, current 304.988983/12076: elapsed=16880.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 304.988983
last_received_ts = 304.988434
last_seq = 12076
current_ts = 305.005859
current_received_ts = 305.005280
current_seq = 12077
count = 126
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 304.988983/12076, current 305.005859/12077: elapsed=16870.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.005859
last_received_ts = 305.005280
last_seq = 12077
current_ts = 305.022736
current_received_ts = 305.022186
current_seq = 12078
count = 127
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.005859/12077, current 305.022736/12078: elapsed=16880.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.022736
last_received_ts = 305.022186
last_seq = 12078
current_ts = 305.039612
current_received_ts = 305.039062
current_seq = 12079
count = 128
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.022736/12078, current 305.039612/12079: elapsed=16867.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.039612
last_received_ts = 305.039062
last_seq = 12079
current_ts = 305.056488
current_received_ts = 305.055939
current_seq = 12080
count = 129
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.039612/12079, current 305.056488/12080: elapsed=16883.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.056488
last_received_ts = 305.055939
last_seq = 12080
current_ts = 305.073364
current_received_ts = 305.072845
current_seq = 12081
count = 130
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.056488/12080, current 305.073364/12081: elapsed=16874.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.073364
last_received_ts = 305.072845
last_seq = 12081
current_ts = 305.090240
current_received_ts = 305.089691
current_seq = 12082
count = 131
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.073364/12081, current 305.090240/12082: elapsed=16876.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.090240
last_received_ts = 305.089691
last_seq = 12082
current_ts = 305.107117
current_received_ts = 305.106567
current_seq = 12083
count = 132
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.090240/12082, current 305.107117/12083: elapsed=16872.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.107117
last_received_ts = 305.106567
last_seq = 12083
current_ts = 305.123993
current_received_ts = 305.123444
current_seq = 12084
count = 133
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.107117/12083, current 305.123993/12084: elapsed=16879.0us expected=16936.6us +- 84.7us, error 0.3%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.123993
last_received_ts = 305.123444
last_seq = 12084
current_ts = 305.140839
current_received_ts = 305.140350
current_seq = 12085
count = 134
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.123993/12084, current 305.140839/12085: elapsed=16865.0us expected=16936.6us +- 84.7us, error 0.4%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.140839
last_received_ts = 305.140350
last_seq = 12085
current_ts = 305.157715
current_received_ts = 305.157104
current_seq = 12086
count = 135
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.140839/12085, current 305.157715/12086: elapsed=16856.0us expected=16936.6us +- 84.7us, error 0.5%
(kms_flip:7609) DEBUG: name = flip
last_ts = 305.157715
last_received_ts = 305.157104
last_seq = 12086
current_ts = 305.174561
current_received_ts = 305.173950
current_seq = 12087
count = 136
seq_step = 1
(kms_flip:7609) DEBUG: flip ts/seq: last 305.157715/12086, current 305.174561/12087: elapsed=16843.0us expected=16936.6us +- 84.7us, error 0.6%
(kms_flip:7609) DEBUG: inconsistent flip ts/seq: last 305.157715/12086, current 305.174561/12087: elapsed=16843.0us expected=16936.6us
(kms_flip:7609) DEBUG: expected 108441, counted 136, encoder type 2
(kms_flip:7609) DEBUG: dropped frames, expected 108441, counted 136, encoder type 2
(kms_flip:7609) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674:
(kms_flip:7609) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon)
(kms_flip:7609) igt_core-INFO: Stack trace:
(kms_flip:7609) igt_core-INFO:   #0 ../lib/igt_core.c:2051 __igt_fail_assert()
(kms_flip:7609) igt_core-INFO:   #1 ../tests/kms_flip.c:791 run_test_on_crtc_set.constprop.0()
(kms_flip:7609) igt_core-INFO:   #2 ../tests/kms_flip.c:1930 run_pair()
(kms_flip:7609) igt_core-INFO:   #3 ../tests/kms_flip.c:2087 __igt_unique____real_main2001()
(kms_flip:7609) igt_core-INFO:   #4 ../tests/kms_flip.c:2001 main()
(kms_flip:7609) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:7609) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:7609) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest AC-DP2-HDMI-A3: FAIL (7.602s)
Starting dynamic subtest: AD-DP2-HDMI-A3
Dynamic subtest AD-DP2-HDMI-A3: SUCCESS (5.668s)
Starting dynamic subtest: BC-DP2-HDMI-A3
Dynamic subtest BC-DP2-HDMI-A3: SUCCESS (5.659s)
Starting dynamic subtest: BD-DP2-HDMI-A3
Dynamic subtest BD-DP2-HDMI-A3: SUCCESS (5.647s)
Starting dynamic subtest: CD-DP2-HDMI-A3
Dynamic subtest CD-DP2-HDMI-A3: SUCCESS (5.650s)
Subtest 2x-plain-flip-ts-check: FAIL (35.354s)