Bug 110722

Summary: [CI][BAT] igt@prime_busy@basic-after-default - fail - Failed assertion: igt_seconds_elapsed(&tv) < timeout
Product: DRI Reporter: Martin Peres <martin.peres>
Component: DRM/IntelAssignee: Jon Ewins <jon.ewins>
Status: RESOLVED WONTFIX QA Contact: Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity: normal    
Priority: high CC: intel-gfx-bugs, jon.ewins
Version: XOrg git   
Hardware: Other   
OS: All   
Whiteboard: ReadyForDev
i915 platform: BXT i915 features: firmware/guc

Description Martin Peres 2019-05-22 07:36:38 UTC 
https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_13061/fi-apl-guc/igt@prime_busy@basic-after-default.html

Starting subtest: basic-after-default
(prime_busy:2932) CRITICAL: Test assertion failure function busy, file ../tests/prime_busy.c:160:
(prime_busy:2932) CRITICAL: Failed assertion: igt_seconds_elapsed(&tv) < timeout
Subtest basic-after-default failed.

<7>[  291.836098] [IGT] prime_busy: starting subtest basic-after-default
<5>[  293.041620] Setting dangerous option reset - tainting kernel
<5>[  293.042291] Setting dangerous option reset - tainting kernel
<5>[  293.056842] Setting dangerous option reset - tainting kernel
<5>[  293.071327] Setting dangerous option reset - tainting kernel
<5>[  293.072756] Setting dangerous option reset - tainting kernel
<5>[  293.087208] Setting dangerous option reset - tainting kernel
<5>[  293.101834] Setting dangerous option reset - tainting kernel
<5>[  293.103166] Setting dangerous option reset - tainting kernel
<5>[  293.117607] Setting dangerous option reset - tainting kernel
<5>[  293.132301] Setting dangerous option reset - tainting kernel
<5>[  293.133472] Setting dangerous option reset - tainting kernel
<5>[  293.148306] Setting dangerous option reset - tainting kernel
<5>[  293.163103] Setting dangerous option reset - tainting kernel
<7>[  293.163673] [IGT] prime_busy: exiting, ret=98
<5>[  293.164104] Setting dangerous option reset - tainting kernel
<7>[  293.365646] __i915_gem_set_wedged rcs0
<7>[  293.365654] __i915_gem_set_wedged 	Awake? 1
<7>[  293.365659] __i915_gem_set_wedged 	Hangcheck: 1528 ms ago
<7>[  293.365663] __i915_gem_set_wedged 	Reset count: 0 (global 1)
<7>[  293.365693] __i915_gem_set_wedged 	Requests:
<7>[  293.365738] __i915_gem_set_wedged 		first   15cd:2-  prio=3 @ 1528ms: prime_busy[2932]
<7>[  293.365744] __i915_gem_set_wedged 		last    15cd:2-  prio=3 @ 1528ms: prime_busy[2932]
<7>[  293.365859] __i915_gem_set_wedged 	RING_START: 0x007ee000
<7>[  293.365866] __i915_gem_set_wedged 	RING_HEAD:  0x00000068
<7>[  293.365873] __i915_gem_set_wedged 	RING_TAIL:  0x00000068
<7>[  293.365883] __i915_gem_set_wedged 	RING_CTL:   0x00000000
<7>[  293.365893] __i915_gem_set_wedged 	RING_MODE:  0x00000200 [idle]
<7>[  293.365900] __i915_gem_set_wedged 	RING_IMR: fffffefe
<7>[  293.365912] __i915_gem_set_wedged 	ACTHD:  0x00000000_00000068
<7>[  293.365925] __i915_gem_set_wedged 	BBADDR: 0x00000000_00000000
<7>[  293.365938] __i915_gem_set_wedged 	DMA_FADDR: 0x00000000_00000000
<7>[  293.365945] __i915_gem_set_wedged 	IPEIR: 0x00000000
<7>[  293.365951] __i915_gem_set_wedged 	IPEHR: 0x00000000
<7>[  293.365962] __i915_gem_set_wedged 	Execlist status: 0x00000301 00000000, entries 6
<7>[  293.365966] __i915_gem_set_wedged 	Execlist CSB read 5, write 1, tasklet queued? no (enabled)
<7>[  293.365971] __i915_gem_set_wedged 	Execlist CSB[0]: 0x00000001, context: 0
<7>[  293.365975] __i915_gem_set_wedged 	Execlist CSB[1]: 0x00000018, context: 2092521
<7>[  293.365983] __i915_gem_set_wedged 		ELSP[0] count=1, ring:{start:00861000, hwsp:fede7200, seqno:00000000}, rq:  15cd:2-  prio=3 @ 1528ms: prime_busy[2932]
<7>[  293.365988] __i915_gem_set_wedged 		ELSP[1] idle
<7>[  293.365992] __i915_gem_set_wedged 		HW active? 0x1
<7>[  293.366019] __i915_gem_set_wedged 		E  15cd:2-  prio=3 @ 1528ms: prime_busy[2932]
<7>[  293.366057] __i915_gem_set_wedged HWSP:
<7>[  293.366064] __i915_gem_set_wedged [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7>[  293.366068] __i915_gem_set_wedged *
<7>[  293.366073] __i915_gem_set_wedged [0040] 00000001 00000000 00000018 001fede9 00000001 00000000 00000018 001fede9
<7>[  293.366079] __i915_gem_set_wedged [0060] 00000001 00000000 00000018 001feda4 00000000 00000000 00000000 00000001
<7>[  293.366084] __i915_gem_set_wedged [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7>[  293.366088] __i915_gem_set_wedged *
<7>[  293.366095] __i915_gem_set_wedged Idle? no
<7>[  293.366100] __i915_gem_set_wedged Signals:
<7>[  293.366122] __i915_gem_set_wedged 	[15cd:2] @ 1528ms
<7>[  293.366158] __i915_gem_set_wedged bcs0
<7>[  293.366162] __i915_gem_set_wedged 	Awake? 0
<7>[  293.366166] __i915_gem_set_wedged 	Hangcheck: 8795 ms ago
<7>[  293.366170] __i915_gem_set_wedged 	Reset count: 0 (global 1)
<7>[  293.366174] __i915_gem_set_wedged 	Requests:
<7>[  293.366195] __i915_gem_set_wedged 	RING_START: 0x007f0000
<7>[  293.366202] __i915_gem_set_wedged 	RING_HEAD:  0x00000028
<7>[  293.366208] __i915_gem_set_wedged 	RING_TAIL:  0x00000028
<7>[  293.366218] __i915_gem_set_wedged 	RING_CTL:   0x00000000
<7>[  293.366228] __i915_gem_set_wedged 	RING_MODE:  0x00000200 [idle]
<7>[  293.366234] __i915_gem_set_wedged 	RING_IMR: feffffff
<7>[  293.366246] __i915_gem_set_wedged 	ACTHD:  0x00000000_00000028
<7>[  293.366259] __i915_gem_set_wedged 	BBADDR: 0x00000000_00000000
<7>[  293.366271] __i915_gem_set_wedged 	DMA_FADDR: 0x00000000_007f0028
<7>[  293.366278] __i915_gem_set_wedged 	IPEIR: 0x00000000
<7>[  293.366284] __i915_gem_set_wedged 	IPEHR: 0x04000001
<7>[  293.366294] __i915_gem_set_wedged 	Execlist status: 0x00000302 00000000, entries 6
<7>[  293.366299] __i915_gem_set_wedged 	Execlist CSB read 5, write 1, tasklet queued? no (enabled)
<7>[  293.366303] __i915_gem_set_wedged 	Execlist CSB[0]: 0x00000001, context: 0
<7>[  293.366307] __i915_gem_set_wedged 	Execlist CSB[1]: 0x00000018, context: 1075834317
<7>[  293.366311] __i915_gem_set_wedged 		ELSP[0] idle
<7>[  293.366315] __i915_gem_set_wedged 		ELSP[1] idle
<7>[  293.366320] __i915_gem_set_wedged 		HW active? 0x0
<7>[  293.366325] __i915_gem_set_wedged HWSP:
<7>[  293.366331] __i915_gem_set_wedged [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7>[  293.366335] __i915_gem_set_wedged *
<7>[  293.366340] __i915_gem_set_wedged [0040] 00000001 00000000 00000018 401fedcd 00000001 00000000 00000018 401fedbb
<7>[  293.366346] __i915_gem_set_wedged [0060] 00000001 00000000 00000018 401fedcd 00000000 00000000 00000000 00000001
<7>[  293.366351] __i915_gem_set_wedged [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7>[  293.366355] __i915_gem_set_wedged *
<7>[  293.366359] __i915_gem_set_wedged Idle? yes
<7>[  293.366363] __i915_gem_set_wedged vcs0
<7>[  293.366367] __i915_gem_set_wedged 	Awake? 0
<7>[  293.366371] __i915_gem_set_wedged 	Hangcheck: 8795 ms ago
<7>[  293.366411] __i915_gem_set_wedged 	Reset count: 0 (global 1)
<7>[  293.366415] __i915_gem_set_wedged 	Requests:
<7>[  293.366461] __i915_gem_set_wedged 	RING_START: 0x007f2000
<7>[  293.366469] __i915_gem_set_wedged 	RING_HEAD:  0x00000028
<7>[  293.366476] __i915_gem_set_wedged 	RING_TAIL:  0x00000028
<7>[  293.366512] __i915_gem_set_wedged 	RING_CTL:   0x00000000
<7>[  293.366522] __i915_gem_set_wedged 	RING_MODE:  0x00000200 [idle]
<7>[  293.366531] __i915_gem_set_wedged 	RING_IMR: fffffeff
<7>[  293.366546] __i915_gem_set_wedged 	ACTHD:  0x00000000_00000028
<7>[  293.366561] __i915_gem_set_wedged 	BBADDR: 0x00000000_00000000
<7>[  293.366576] __i915_gem_set_wedged 	DMA_FADDR: 0x00000000_007f2028
<7>[  293.366585] __i915_gem_set_wedged 	IPEIR: 0x00000000
<7>[  293.366594] __i915_gem_set_wedged 	IPEHR: 0x04000001
<7>[  293.366607] __i915_gem_set_wedged 	Execlist status: 0x00000302 00000000, entries 6
<7>[  293.366613] __i915_gem_set_wedged 	Execlist CSB read 5, write 1, tasklet queued? no (enabled)
<7>[  293.366620] __i915_gem_set_wedged 	Execlist CSB[0]: 0x00000001, context: 0
<7>[  293.366625] __i915_gem_set_wedged 	Execlist CSB[1]: 0x00000018, context: 538963399
<7>[  293.366632] __i915_gem_set_wedged 		ELSP[0] idle
<7>[  293.366639] __i915_gem_set_wedged 		ELSP[1] idle
<7>[  293.366646] __i915_gem_set_wedged 		HW active? 0x0
<7>[  293.366654] __i915_gem_set_wedged HWSP:
<7>[  293.366661] __i915_gem_set_wedged [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7>[  293.366666] __i915_gem_set_wedged *
<7>[  293.366673] __i915_gem_set_wedged [0040] 00000001 00000000 00000018 201fedc7 00000001 00000000 00000018 201fedc7
<7>[  293.366681] __i915_gem_set_wedged [0060] 00000001 00000000 00000018 201fedc7 00000000 00000000 00000000 00000001
<7>[  293.366687] __i915_gem_set_wedged [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7>[  293.366692] __i915_gem_set_wedged *
<7>[  293.366698] __i915_gem_set_wedged Idle? yes
<7>[  293.366705] __i915_gem_set_wedged vecs0
<7>[  293.366710] __i915_gem_set_wedged 	Awake? 0
<7>[  293.366716] __i915_gem_set_wedged 	Hangcheck: 8796 ms ago
<7>[  293.366721] __i915_gem_set_wedged 	Reset count: 0 (global 1)
<7>[  293.366726] __i915_gem_set_wedged 	Requests:
<7>[  293.366739] __i915_gem_set_wedged 	RING_START: 0x007f4000
<7>[  293.366746] __i915_gem_set_wedged 	RING_HEAD:  0x00000028
<7>[  293.366753] __i915_gem_set_wedged 	RING_TAIL:  0x00000028
<7>[  293.366762] __i915_gem_set_wedged 	RING_CTL:   0x00000000
<7>[  293.366771] __i915_gem_set_wedged 	RING_MODE:  0x00000200 [idle]
<7>[  293.366778] __i915_gem_set_wedged 	RING_IMR: fffffeff
<7>[  293.366791] __i915_gem_set_wedged 	ACTHD:  0x00000000_00000028
<7>[  293.366803] __i915_gem_set_wedged 	BBADDR: 0x00000000_00000000
<7>[  293.366815] __i915_gem_set_wedged 	DMA_FADDR: 0x00000000_007f4028
<7>[  293.366822] __i915_gem_set_wedged 	IPEIR: 0x00000000
<7>[  293.366828] __i915_gem_set_wedged 	IPEHR: 0x04000001
<7>[  293.366838] __i915_gem_set_wedged 	Execlist status: 0x00000302 00000000, entries 6
<7>[  293.366843] __i915_gem_set_wedged 	Execlist CSB read 5, write 1, tasklet queued? no (enabled)
<7>[  293.366847] __i915_gem_set_wedged 	Execlist CSB[0]: 0x00000001, context: 0
<7>[  293.366851] __i915_gem_set_wedged 	Execlist CSB[1]: 0x00000018, context: 1612705217
<7>[  293.366855] __i915_gem_set_wedged 		ELSP[0] idle
<7>[  293.366859] __i915_gem_set_wedged 		ELSP[1] idle
<7>[  293.366863] __i915_gem_set_wedged 		HW active? 0x0
<7>[  293.366869] __i915_gem_set_wedged HWSP:
<7>[  293.366874] __i915_gem_set_wedged [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7>[  293.366878] __i915_gem_set_wedged *
<7>[  293.366883] __i915_gem_set_wedged [0040] 00000001 00000000 00000018 601fedc1 00000001 00000000 00000018 601fedc1
<7>[  293.366889] __i915_gem_set_wedged [0060] 00000001 00000000 00000018 601fedc1 00000000 00000000 00000000 00000001
<7>[  293.366897] __i915_gem_set_wedged [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7>[  293.366903] __i915_gem_set_wedged *
<7>[  293.366909] __i915_gem_set_wedged Idle? yes
<7>[  293.369538] [drm:i915_reset_device [i915]] resetting chip
<7>[  293.372833] [drm:intel_uc_fw_upload [i915]] HuC fw load i915/bxt_huc_ver01_8_2893.bin
<7>[  293.372914] [drm:intel_uc_fw_upload [i915]] HuC fw load PENDING
<7>[  293.373447] [drm:huc_fw_xfer [i915]] HuC DMA transfer wait over with ret 0
<7>[  293.373884] [drm:intel_uc_fw_upload [i915]] HuC fw load SUCCESS
<6>[  293.373889] [drm] HuC: Loaded firmware i915/bxt_huc_ver01_8_2893.bin (version 1.8)
<7>[  293.373967] [drm:intel_guc_init_params [i915]] param[ 0] = 0x816040
<7>[  293.374042] [drm:intel_guc_init_params [i915]] param[ 1] = 0x0
<7>[  293.374117] [drm:intel_guc_init_params [i915]] param[ 2] = 0x5f5e100
<7>[  293.374193] [drm:intel_guc_init_params [i915]] param[ 3] = 0x0
<7>[  293.374269] [drm:intel_guc_init_params [i915]] param[ 4] = 0x7f7fd3
<7>[  293.374344] [drm:intel_guc_init_params [i915]] param[ 5] = 0x0
<7>[  293.374420] [drm:intel_guc_init_params [i915]] param[ 6] = 0x8
<7>[  293.374795] [drm:intel_guc_init_params [i915]] param[ 7] = 0x3
<7>[  293.374871] [drm:intel_guc_init_params [i915]] param[ 8] = 0x405203
<7>[  293.374946] [drm:intel_guc_init_params [i915]] param[ 9] = 0x0
<7>[  293.375021] [drm:intel_guc_init_params [i915]] param[10] = 0x0
<7>[  293.375096] [drm:intel_guc_init_params [i915]] param[11] = 0x0
<7>[  293.375171] [drm:intel_guc_init_params [i915]] param[12] = 0x0
<7>[  293.375246] [drm:intel_guc_init_params [i915]] param[13] = 0x0
<7>[  293.375346] [drm:intel_uc_fw_upload [i915]] GuC fw load i915/bxt_guc_ver9_29.bin
<7>[  293.375421] [drm:intel_uc_fw_upload [i915]] GuC fw load PENDING
<7>[  293.380535] [drm:guc_fw_xfer [i915]] GuC status 0x8002f0ec
<7>[  293.380620] [drm:intel_uc_fw_upload [i915]] GuC fw load SUCCESS
<6>[  293.380625] [drm] GuC: Loaded firmware i915/bxt_guc_ver9_29.bin (version 9.29)
<7>[  293.380817] [drm:__guc_client_enable [i915]] Host engines 0x47 => GuC engines used 0xf
<7>[  293.382360] [drm:__guc_client_enable [i915]] Host engines 0x47 => GuC engines used 0xf
<6>[  293.382744] i915 0000:00:02.0: GuC firmware version 9.29
<6>[  293.382749] i915 0000:00:02.0: GuC submission enabled
<6>[  293.382753] i915 0000:00:02.0: HuC enabled
<6>[  293.426667] Console: switching to colour frame buffer device 240x67
<6>[  293.644809] Console: switching to colour dummy device 80x25
Comment 2 Lakshmi 2019-06-27 11:00:45 UTC 
Occurred only once CI_DRM_6109 (1 month, 1 week old). Dropping the priority to High for now.
Comment 3 Daniele Ceraolo Spurio 2019-07-26 22:49:19 UTC 
This is a bug with old-style GuC submission on the old FW. GuC submission is currently disabled and we're going to re-enable it with a completely new flow, so closing this bug.
Comment 4 Martin Peres 2019-08-21 12:43:10 UTC 
(In reply to Daniele Ceraolo Spurio from comment #3)
> This is a bug with old-style GuC submission on the old FW. GuC submission is
> currently disabled and we're going to re-enable it with a completely new
> flow, so closing this bug.

Thanks Daniele!
Comment 5 CI Bug Log 2019-08-21 12:43:17 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.

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.