Bug 103060 - [CI] igt@kms_flip@*-vs-vblank-race* - Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
Summary: [CI] igt@kms_flip@*-vs-vblank-race* - Failed assertion: end - start > 0.9 * m...
Status: NEW
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: Other All
: medium normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords:
: 102919 (view as bug list)
Depends on:
Blocks:
 
Reported: 2017-10-02 09:39 UTC by Marta Löfstedt
Modified: 2019-04-04 11:56 UTC (History)
1 user (show)

See Also:
i915 platform: BXT, CNL, GLK, HSW, ICL, SKL, SNB
i915 features: display/Other


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Marta Löfstedt 2017-10-02 09:39:52 UTC
CI_DRM_3159 snb-shards igt@kms_flip@dpms-vs-vblank-race fail:

(kms_flip:1595) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:780:
(kms_flip:1595) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1595) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:1595) CRITICAL: wait for two vblanks took 51717 usec (frame time 16665.600000 usec)
Subtest dpms-vs-vblank-race failed.

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3159/shard-hsw5/igt@kms_flip@dpms-vs-vblank-race.html
Comment 1 Marta Löfstedt 2017-10-16 06:28:44 UTC
Also, CI_DRM_3237 APL-shards:

 (kms_flip:1343) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:780:
(kms_flip:1343) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1343) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:1343) CRITICAL: wait for two vblanks took 38557 usec (frame time 16665.600000 usec)
Subtest dpms-vs-vblank-race-interruptible failed.

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3237/shard-apl1/igt@kms_flip@dpms-vs-vblank-race-interruptible.html
Comment 2 Marta Löfstedt 2017-10-17 06:57:53 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3244/shard-apl3/igt@kms_flip@modeset-vs-vblank-race.html

(kms_flip:3752) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:780:
(kms_flip:3752) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:3752) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:3752) CRITICAL: wait for two vblanks took 64841 usec (frame time 16665.600000 usec)
Subtest modeset-vs-vblank-race failed.
Comment 3 Marta Löfstedt 2017-10-18 10:31:03 UTC
Also, CI_DRM_3252 GLK-shards 

(kms_flip:1606) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:780:
(kms_flip:1606) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1606) CRITICAL: wait for two vblanks took 49618 usec (frame time 16666.378441 usec)
Subtest dpms-vs-vblank-race failed.

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3252/shard-glkb2/igt@kms_flip@dpms-vs-vblank-race.html
Comment 4 Marta Löfstedt 2017-10-18 10:39:34 UTC
Also, GLK-shards:

(kms_flip:2685) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:780:
(kms_flip:2685) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:2685) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2685) CRITICAL: wait for two vblanks took 49324 usec (frame time 16666.378441 usec)
Subtest modeset-vs-vblank-race-interruptible failed.

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3253/shard-glkb2/igt@kms_flip@modeset-vs-vblank-race-interruptible.html
Comment 5 Marta Löfstedt 2017-11-03 07:32:57 UTC
*** Bug 102919 has been marked as a duplicate of this bug. ***
Comment 6 Marta Löfstedt 2017-12-18 13:26:23 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3539/shard-snb3/igt@kms_flip@modeset-vs-vblank-race.html

(kms_flip:1429) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:780:
(kms_flip:1429) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1429) CRITICAL: wait for two vblanks took 46119 usec (frame time 16665.600000 usec)
Subtest modeset-vs-vblank-race failed.
Comment 7 Marta Löfstedt 2018-01-30 07:28:13 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3688/shard-hsw6/igt@kms_flip@2x-modeset-vs-vblank-race.html

	
(kms_flip:6120) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:763:
(kms_flip:6120) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:6120) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:6120) CRITICAL: wait for two vblanks took 36105 usec (frame time 16665.600000 usec)
Subtest 2x-modeset-vs-vblank-race failed.
Comment 8 Marta Löfstedt 2018-02-06 07:49:32 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3723/shard-hsw5/igt@kms_flip@2x-dpms-vs-vblank-race-interruptible.html

(kms_flip:7296) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:763:
(kms_flip:7296) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:7296) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:7296) CRITICAL: wait for two vblanks took 37261 usec (frame time 16665.600000 usec)
Subtest 2x-dpms-vs-vblank-race-interruptible failed.
Comment 9 Marta Löfstedt 2018-02-07 12:07:31 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4227/shard-hsw5/igt@kms_flip@2x-dpms-vs-vblank-race.html

(kms_flip:17014) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:763:
(kms_flip:17014) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:17014) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:17014) CRITICAL: wait for two vblanks took 41085 usec (frame time 16665.600000 usec)
Subtest 2x-dpms-vs-vblank-race failed.
Comment 10 Marta Löfstedt 2018-02-16 07:02:34 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4256/shard-hsw6/igt@kms_flip@2x-modeset-vs-vblank-race-interruptible.html

(kms_flip:31512) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:763:
(kms_flip:31512) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:31512) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:31512) CRITICAL: wait for two vblanks took 37954 usec (frame time 16665.600000 usec)
Subtest 2x-modeset-vs-vblank-race-interruptible failed.
Comment 11 Marta Löfstedt 2018-03-12 11:08:13 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-drrs/igt@kms_flip@modeset-vs-vblank-race-interruptible.html

(kms_flip:2975) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:763:
(kms_flip:2975) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:2975) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2975) CRITICAL: wait for two vblanks took 49658 usec (frame time 16666.378441 usec)

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-y3/igt@kms_flip@modeset-vs-vblank-race-interruptible.html

(kms_flip:2998) CRITICAL: Test assertion failure function run_test_step, file kms_flip.c:763:
(kms_flip:2998) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:2998) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2998) CRITICAL: wait for two vblanks took 40912 usec (frame time 16667.604313 usec)
Subtest modeset-vs-vblank-race-interruptible failed.

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-drrs/igt@kms_flip@modeset-vs-vblank-race.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-y3/igt@kms_flip@modeset-vs-vblank-race.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-drrs/igt@kms_flip@dpms-vs-vblank-race-interruptible.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-y3/igt@kms_flip@dpms-vs-vblank-race-interruptible.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-drrs/igt@kms_flip@dpms-vs-vblank-race.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-y3/igt@kms_flip@dpms-vs-vblank-race.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-y3/igt@kms_flip@2x-modeset-vs-vblank-race-interruptible.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-y3/igt@kms_flip@2x-modeset-vs-vblank-race.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-y3/igt@kms_flip@2x-dpms-vs-vblank-race-interruptible.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3903/fi-cnl-y3/igt@kms_flip@2x-dpms-vs-vblank-race.html
Comment 12 Marta Löfstedt 2018-03-16 07:26:26 UTC
From shardlist on BAT machines runs fi_skl_6600u hit:

(kms_flip:1763) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:763:
(kms_flip:1763) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1763) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:1763) CRITICAL: wait for two vblanks took 40335 usec (frame time 16671.721366 usec)


https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-skl-6600u/igt@kms_flip@modeset-vs-vblank-race-interruptible.html
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-skl-6600u/igt@kms_flip@modeset-vs-vblank-race.html
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-skl-6600u/igt@kms_flip@dpms-vs-vblank-race-interruptible.html
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-skl-6600u/igt@kms_flip@dpms-vs-vblank-race.html
Comment 13 Marta Löfstedt 2018-03-19 07:34:18 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-ilk-m540/igt@kms_flip@2x-modeset-vs-vblank-race.html
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-ilk-m540/igt@kms_flip@2x-modeset-vs-vblank-race-interruptible.html
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-ilk-m540/igt@kms_flip@modeset-vs-vblank-race.html
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-ilk-m540/igt@kms_flip@modeset-vs-vblank-race-interruptible.html

(kms_flip:1442) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:763:
(kms_flip:1442) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1442) CRITICAL: wait for two vblanks took 49734 usec (frame time 16670.871985 usec)
Subtest 2x-modeset-vs-vblank-race failed.
Comment 14 Marta Löfstedt 2018-03-19 07:39:53 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_2/fi-bsw-n3050/igt@kms_flip@dpms-vs-vblank-race-interruptible.html
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_1/fi-bsw-n3050/igt@kms_flip@dpms-vs-vblank-race.html

(kms_flip:1515) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:763:
(kms_flip:1515) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1515) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:1515) CRITICAL: wait for two vblanks took 37918 usec (frame time 16680.519481 usec)
Subtest dpms-vs-vblank-race-interruptible failed.
Comment 15 Marta Löfstedt 2018-03-19 15:07:39 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_4/fi-skl-gvtdvm/igt@kms_flip@dpms-vs-vblank-race.html

(kms_flip:1248) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:763:
(kms_flip:1248) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1248) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:1248) CRITICAL: wait for two vblanks took 36273 usec (frame time 16672.736573 usec)
Subtest dpms-vs-vblank-race failed.
Comment 16 Marta Löfstedt 2018-03-21 09:48:19 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_5/fi-bdw-gvtdvm/igt@kms_flip@modeset-vs-vblank-race.html

(kms_flip:1301) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:763:
(kms_flip:1301) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1301) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:1301) CRITICAL: wait for two vblanks took 38360 usec (frame time 16672.736573 usec)
Subtest modeset-vs-vblank-race failed.
Comment 18 Marta Löfstedt 2018-04-12 08:07:07 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_4046/shard-glk3/igt@kms_flip@dpms-vs-vblank-race.html


(kms_flip:1243) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:763:
(kms_flip:1243) CRITICAL: Failed assertion: end - start > 0.9 * mode_frame_time(o) && end - start < 2.1 * mode_frame_time(o)
(kms_flip:1243) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:1243) CRITICAL: wait for two vblanks took 37473 usec (frame time 16666.666667 usec)
Subtest dpms-vs-vblank-race failed.
Comment 19 CI Bug Log 2019-04-04 11:42:16 UTC
The CI Bug Log issue associated to this bug has been archived.

New failures matching the above filters will not be associated to this bug anymore.
Comment 20 Martin Peres 2019-04-04 11:48:51 UTC
(In reply to CI Bug Log from comment #19)
> The CI Bug Log issue associated to this bug has been archived.
> 
> New failures matching the above filters will not be associated to this bug
> anymore.

There was 2 issues associated to this bug, one being a super-set of the other. I closed the smaller one since it was useless.
Comment 21 Daniel Vetter 2019-04-04 11:49:47 UTC
Need to figure out why we stall and the vblank wait takes longer (sometimes a lot longer) than we expect. Best way probably is grab the ftrace flight recorder log when this happens and dump it, since reproducibility is pretty low.

The delay is sometimes multiple frames, so not something we can just shrug off as statistical noise.
Comment 22 Martin Peres 2019-04-04 11:56:28 UTC
Customer impact could be increased stuttering when watching videos or playing games. More information needs to be collected in order to improve our understanding of the issue, but a medium priority seems appropriate.


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.