Bug 110176 - [CI][DRMTIP] igt@kms_flip@wf_vblank-ts-check.* - Failed assertion: fabs((elapsed - expected) / expected) <= 0.005
Summary: [CI][DRMTIP] igt@kms_flip@wf_vblank-ts-check.* - Failed assertion: fabs((elap...
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:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-03-18 13:23 UTC by Lakshmi
Modified: 2019-04-09 06:40 UTC (History)
1 user (show)

See Also:
i915 platform: ICL
i915 features: display/Other


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Lakshmi 2019-03-18 13:23:37 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_246/fi-icl-y/igt@kms_flip@wf_vblank-ts-check.html

Starting subtest: wf_vblank-ts-check
(kms_flip:2171) CRITICAL: Test assertion failure function check_state, file ../tests/kms_flip.c:519:
(kms_flip:2171) CRITICAL: Failed assertion: fabs((elapsed - expected) / expected) <= 0.005
(kms_flip:2171) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:2171) CRITICAL: inconsistent vblank ts/seq: last 402.103943/19683, current 402.337280/19693: elapsed=233348.0us expected=166671.2us
Subtest wf_vblank-ts-check failed.
**** DEBUG ****
(kms_flip:2171) DEBUG: Test requirement passed: (flags & TEST_HANG) == 0 || !is_wedged(drm_fd)
(kms_flip:2171) DEBUG: Test requirement passed: resources
(kms_flip:2171) DEBUG: Test requirement passed: modes
(kms_flip:2171) INFO: Beginning wf_vblank-ts-check on pipe A, connector eDP-1
(kms_flip:2171) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_flip:2171) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680)
(kms_flip:2171) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2171) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_flip:2171) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=3, pitch=7680)
(kms_flip:2171) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2171) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS
(kms_flip:2171) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS
(kms_flip:2171) igt_kms-INFO:   1920x1080 60 1920 1966 1996 2080 1080 1082 1086 1112 0xa 0x48 138780
(kms_flip:2171) INFO: Expected frametime: 16666us; measured 16667.1us +- 5.340us accuracy 0.10%
(kms_flip:2171) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 401.270630
current_received_ts = 401.270264
current_seq = 19633
count = 0
seq_step = 10
(kms_flip:2171) DEBUG: name = vblank
last_ts = 401.270630
last_received_ts = 401.270264
last_seq = 19633
current_ts = 401.437286
current_received_ts = 401.436981
current_seq = 19643
count = 1
seq_step = 10
(kms_flip:2171) DEBUG: vblank ts/seq: last 401.270630/19633, current 401.437286/19643: elapsed=166676.0us expected=166671.2us +- 833.4us, error 0.0%
(kms_flip:2171) DEBUG: name = vblank
last_ts = 401.437286
last_received_ts = 401.436981
last_seq = 19643
current_ts = 401.603973
current_received_ts = 401.603607
current_seq = 19653
count = 2
seq_step = 10
(kms_flip:2171) DEBUG: vblank ts/seq: last 401.437286/19643, current 401.603973/19653: elapsed=166661.0us expected=166671.2us +- 833.4us, error 0.0%
(kms_flip:2171) DEBUG: name = vblank
last_ts = 401.603973
last_received_ts = 401.603607
last_seq = 19653
current_ts = 401.770630
current_received_ts = 401.770233
current_seq = 19663
count = 3
seq_step = 10
(kms_flip:2171) DEBUG: vblank ts/seq: last 401.603973/19653, current 401.770630/19663: elapsed=166661.0us expected=166671.2us +- 833.4us, error 0.0%
(kms_flip:2171) DEBUG: name = vblank
last_ts = 401.770630
last_received_ts = 401.770233
last_seq = 19663
current_ts = 401.937286
current_received_ts = 401.936981
current_seq = 19673
count = 4
seq_step = 10
(kms_flip:2171) DEBUG: vblank ts/seq: last 401.770630/19663, current 401.937286/19673: elapsed=166667.0us expected=166671.2us +- 833.4us, error 0.0%
(kms_flip:2171) DEBUG: name = vblank
last_ts = 401.937286
last_received_ts = 401.936981
last_seq = 19673
current_ts = 402.103943
current_received_ts = 402.103638
current_seq = 19683
count = 5
seq_step = 10
(kms_flip:2171) DEBUG: vblank ts/seq: last 401.937286/19673, current 402.103943/19683: elapsed=166656.0us expected=166671.2us +- 833.4us, error 0.0%
(kms_flip:2171) DEBUG: name = vblank
last_ts = 402.103943
last_received_ts = 402.103638
last_seq = 19683
current_ts = 402.337280
current_received_ts = 402.336945
current_seq = 19693
count = 6
seq_step = 10
(kms_flip:2171) DEBUG: vblank ts/seq: last 402.103943/19683, current 402.337280/19693: elapsed=233348.0us expected=166671.2us +- 833.4us, error 40.0%
(kms_flip:2171) CRITICAL: Test assertion failure function check_state, file ../tests/kms_flip.c:519:
(kms_flip:2171) CRITICAL: Failed assertion: fabs((elapsed - expected) / expected) <= 0.005
(kms_flip:2171) CRITICAL: Last errno: 25, Inappropriate ioctl for device
(kms_flip:2171) CRITICAL: inconsistent vblank ts/seq: last 402.103943/19683, current 402.337280/19693: elapsed=233348.0us expected=166671.2us
(kms_flip:2171) igt_core-INFO: Stack trace:
(kms_flip:2171) igt_core-INFO:   #0 ../lib/igt_core.c:1474 __igt_fail_assert()
(kms_flip:2171) igt_core-INFO:   #1 ../tests/kms_flip.c:521 check_state()
(kms_flip:2171) igt_core-INFO:   #2 ../tests/kms_flip.c:568 check_all_state()
(kms_flip:2171) igt_core-INFO:   #3 ../tests/kms_flip.c:1051 event_loop()
(kms_flip:2171) igt_core-INFO:   #4 ../tests/kms_flip.c:1291 run_test_on_crtc_set()
(kms_flip:2171) igt_core-INFO:   #5 ../tests/kms_flip.c:1346 run_test()
(kms_flip:2171) igt_core-INFO:   #6 ../tests/kms_flip.c:1558 main()
(kms_flip:2171) igt_core-INFO:   #7 ../csu/libc-start.c:344 __libc_start_main()
(kms_flip:2171) igt_core-INFO:   #8 [_start+0x2a]
****  END  ****
Subtest wf_vblank-ts-check: FAIL (2.917s)
Comment 2 CI Bug Log 2019-03-18 13:41:31 UTC
A CI Bug Log filter associated to this bug has been updated:

{- ICL: igt@kms_flip@wf_vblank-ts-check.* - Failed assertion: fabs((elapsed - expected) / expected) &lt;= 0.005 -}
{+ ICL: igt@kms_flip@wf_vblank-ts-check.* -fail - Failed assertion: fabs((elapsed - expected) / expected) &lt;= 0.005 +}

 No new failures caught with the new filter
Comment 3 CI Bug Log 2019-03-18 13:42:02 UTC
A CI Bug Log filter associated to this bug has been updated:

{- ICL: igt@kms_flip@wf_vblank-ts-check.* -fail - Failed assertion: fabs((elapsed - expected) / expected) &lt;= 0.005 -}
{+ ICL: igt@kms_flip@wf_vblank-ts-check.* -fail - Failed assertion: fabs((elapsed - expected) / expected) &lt;= 0.005 +}

 No new failures caught with the new filter
Comment 4 Lakshmi 2019-03-21 12:54:07 UTC
This is occurring on every drmtip run since drmtip-243 and occurring only on fi-icl-y.
Comment 5 CI Bug Log 2019-04-09 06:40:57 UTC
A CI Bug Log filter associated to this bug has been updated:

{- ICL: igt@kms_flip@wf_vblank-ts-check.* -fail - Failed assertion: fabs((elapsed - expected) / expected) &lt;= 0.005 -}
{+ ICL: igt@kms_flip@*wf_vblank* -fail - Failed assertion: fabs((elapsed - expected) / expected) &lt;= 0.005 +}

New failures caught by the filter:

* https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_248/fi-icl-y/igt@kms_flip@blocking-wf_vblank.html
* https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_249/fi-icl-y/igt@kms_flip@blocking-wf_vblank.html
* https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_250/fi-icl-y/igt@kms_flip@blocking-wf_vblank.html


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.