Bug 99910 - [KBL/BXT] [IGT] gem_exec_latency render-dispatch-queued fails
Summary: [KBL/BXT] [IGT] gem_exec_latency render-dispatch-queued fails
Status: CLOSED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: x86-64 (AMD64) Linux (All)
: medium normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-02-22 18:40 UTC by Luis Botello
Modified: 2017-07-24 22:39 UTC (History)
1 user (show)

See Also:
i915 platform: BXT, KBL
i915 features: GEM/execlists


Attachments
dmesg_gem_exec_latency (105.23 KB, text/plain)
2017-02-24 00:10 UTC, Luis Botello
no flags Details

Description Luis Botello 2017-02-22 18:40:55 UTC
HW config
===============================
Processor Number				i7-7500U
Processor Graphics 				Intel® HD Graphics 620
Graphics Base Frequency				300.00 MHz
Graphics Max Dynamic Frequency			1.05 GHz
Graphics Video Max Memory			32 GB
Graphics Output					eDP/DP/HDMI/DVI

SW config
=================================
Kernel version : 4.10.0-rc8-e80b772
commit e80b772bf85da72c46b582e7c4f7b0d861cb4669
    drm-tip: 2017y-02m-14d-22h-44m-17s UTC integration manifest
Component         : drm
	tag       : libdrm-2.4.75-6-gec80fd3
	commit    : ec80fd3
 Component         : cairo
	tag       : 1.15.4-6-g5854dd9
	commit    : 5854dd9
Component         : intel-gpu-tools
	tag       : intel-gpu-tools-1.17-240-gca2ba47
	commit    : ca2ba47

Steps
====================================
./kms_busy --run-subtest extended-modeset-hang-newfb-blt-a

Program output
=====================================
Using Execlists submission
(gem_exec_latency:1546) igt-vgem-CRITICAL: Test assertion failure function vgem_fence_signal, file igt_vgem.c:191:
(gem_exec_latency:1546) igt-vgem-CRITICAL: Failed assertion: __vgem_fence_signal(fd, fence) == 0
(gem_exec_latency:1546) igt-vgem-CRITICAL: error: -110 != 0
Stack trace:
  #0 [__igt_fail_assert+0x101]
  #1 [vgem_fence_signal+0x44]
  #2 [latency_on_ring+0x2df]
  #3 [__real_main389+0x2ec]
  #4 [main+0x33]
  #5 [__libc_start_main+0xf1]
  #6 [_start+0x29]
  #7 [<unknown>+0x29]
Subtest render-dispatch-queued failed.
**** DEBUG ****
(gem_exec_latency:1546) ioctl-wrappers-DEBUG: Test requirement passed: gem_has_ring(fd, ring)
(gem_exec_latency:1546) drmtest-DEBUG: Test requirement passed: !(fd<0)
(gem_exec_latency:1546) igt-vgem-CRITICAL: Test assertion failure function vgem_fence_signal, file igt_vgem.c:191:
(gem_exec_latency:1546) igt-vgem-CRITICAL: Failed assertion: __vgem_fence_signal(fd, fence) == 0
(gem_exec_latency:1546) igt-vgem-CRITICAL: error: -110 != 0
****  END  ****
Subtest render-dispatch-queued: FAIL (10.195s)

dmesg
===============================================
[  157.656283] Console: switching to colour dummy device 80x25
[  157.656320] [IGT] gem_exec_latency: executing
[  157.657217] [drm:intel_ring_workarounds_emit [i915]] Number of Workarounds emitted: 17
[  157.713132] [IGT] gem_exec_latency: starting subtest render-dispatch-queued
[  157.717221] [drm:vgem_gem_dumb_create [vgem]] Created object of size 1
[  167.904825] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904829] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904831] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904833] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904834] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904836] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904838] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904839] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904841] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904843] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904844] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904846] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904847] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904849] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904851] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904852] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904854] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904856] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904857] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904859] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904863] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904867] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904869] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904871] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904873] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904874] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904876] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904877] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904879] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904880] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904882] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904884] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904885] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904887] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904888] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904890] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904891] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904893] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904895] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904896] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904898] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904899] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904901] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904902] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904904] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904906] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904907] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904909] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904910] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904912] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904914] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904915] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904917] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904918] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904920] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904922] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904923] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904925] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904926] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904928] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904930] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904931] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904933] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904934] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904936] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904937] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904939] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904940] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904942] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904944] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904945] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904947] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904948] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904950] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904952] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904953] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904955] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904956] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904958] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904959] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904961] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904963] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904964] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904966] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904968] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904969] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904971] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904972] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904974] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904976] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904977] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904979] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904981] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904982] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904984] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904985] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904987] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904989] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904990] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904992] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904994] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904995] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904997] asynchronous wait on fence vgem:unbound:1 timed out
[  167.904998] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905000] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905002] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905003] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905005] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905006] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905008] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905010] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905011] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905013] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905015] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905016] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905018] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905019] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905021] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905023] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905024] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905026] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905027] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905029] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905031] asynchronous wait on fence vgem:unbound:1 timed out
[  167.905032] asynchronous wait on fence vgem:unbound:1 timed out
[  167.908134] [IGT] gem_exec_latency: exiting, ret=99
[  167.908359] [drm:intel_ring_workarounds_emit [i915]] Number of Workarounds emitted: 17
[  167.958594] Console: switching to colour frame buffer device 240x67
Comment 1 Luis Botello 2017-02-22 18:50:51 UTC
Please ignore the section Steps in the previous comment, this is the correct:
Steps:
========================================
./gem_exec_latency --run-subtest render-dispatch-queued
Comment 2 Jairo Miramontes 2017-02-22 18:55:10 UTC
These two tests are failing on BXT as well:

igt@gem_exec_latency@render-synchronisation-queued
igt@gem_exec_latency@render-dispatch-queued


========== Kernel Information==========
commit e80b772bf85da72c46b582e7c4f7b0d861cb4669
Author: Daniel Vetter <daniel.vetter@ffwll.ch>
Date:   Tue Feb 14 23:45:02 2017 +0100

    drm-tip: 2017y-02m-14d-22h-44m-17s UTC integration manifest


Kernel version : 4.10.0-rc8-e80b772
Architecture : source amd64 all

========== Software Information ==========
Component: drm
Url      : http://cgit.freedesktop.org/mesa/drm
Tag      : libdrm-2.4.75-6-gec80fd3
Commit   : ec80fd3
Author   : Chris Wilson <chris@chris-wilson.co.uk>
Age      : 2 days ago

Component: cairo
Url      : http://cgit.freedesktop.org/cairo
Tag      : 1.15.4-6-g5854dd9
Commit   : 5854dd9
Author   : Adrian Johnson <ajohnson@redneon.com>
Age      : 12 days ago

Component: intel-gpu-tools
Url      : https://cgit.freedesktop.org/xorg/app/intel-gpu-tools
Tag      : intel-gpu-tools-1.17-240-gca2ba47
Commit   : ca2ba47
Author   : Chris Wilson <chris@chris-wilson.co.uk>
Age      : 15 hours ago

====================

Ubuntu 16.10 yakkety
Comment 3 Chris Wilson 2017-02-22 20:00:14 UTC
What's the status on skl and bdw (then less importantly, bsw, ivb, hsw, byt)? It's working for me, so please attach the full dmesg.
Comment 4 Luis Botello 2017-02-24 00:10:44 UTC
Created attachment 129890 [details]
dmesg_gem_exec_latency
Comment 5 Luis Botello 2017-02-24 00:10:58 UTC
This is the status for other platforms:

BSW - pass - drm-intel-qa 4.10.0-rc8 58294e4
HSW - pass - drm-intel-qa 4.10.0-rc8 58294e4
BYT - pass - drm-intel-qa 4.10.0-rc8 58294e4
BDW - pass - drm-intel-qa 4.10.0-rc8 58294e4
SKL - fail - drm-tip-qa-commit-e80b772
KBL - fail - drm-tip-qa-commit-e80b772

Added dmesg_gem_exec_latency
Comment 6 Chris Wilson 2017-02-24 12:33:58 UTC
Hmm, ring_size is the same for gen8 and gen9. Not using the guc, so not overflowing the wq. Puzzling.
Comment 7 Chris Wilson 2017-02-24 12:34:34 UTC
Maybe gen9 requests are typically much larger than gen8...
Comment 8 Chris Wilson 2017-03-01 11:01:59 UTC
commit ef999ae40f30f11f4156c7749dac76b60188ffe7
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Mar 1 10:57:06 2017 +0000

    igt/gem_exec_latency: Measure ring size
    
    Measure the ring size and limit the number of our batches to avoid
    stalling (and livelocks) by waiting upon queued batches.
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=99910
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

(I believe should fix this)


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.