Bug 108887

Summary: [CI][SHARDS] igt@gem_userptr_blits@readonly-unsync - timeout
Product: DRI Reporter: Martin Peres <martin.peres>
Component: DRM/IntelAssignee: Joonas Lahtinen <joonas.lahtinen>
Status: CLOSED FIXED QA Contact: Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity: normal    
Priority: high CC: intel-gfx-bugs
Version: XOrg git   
Hardware: Other   
OS: All   
Whiteboard: ReadyForDev
i915 platform: BDW, CFL, GLK, ICL, KBL, SKL i915 features: GEM/Other

Description Martin Peres 2018-11-28 12:41:01 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5210/shard-skl1/igt@gem_userptr_blits@readonly-unsync.html

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5211/shard-skl2/igt@gem_userptr_blits@readonly-unsync.html

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4732/shard-skl10/igt@gem_userptr_blits@readonly-unsync.html

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4733/shard-skl9/igt@gem_userptr_blits@readonly-unsync.html

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4735/shard-skl6/igt@gem_userptr_blits@readonly-unsync.html

<6> [546.921019] Console: switching to colour dummy device 80x25
<6> [546.921712] [IGT] gem_userptr_blits: executing
<6> [546.994223] [IGT] gem_userptr_blits: starting subtest readonly-unsync
<7> [549.455652] [drm:edp_panel_vdd_off_sync [i915]] Turning eDP port A VDD off
<7> [549.455995] [drm:edp_panel_vdd_off_sync [i915]] PP_STATUS: 0x80000008 PP_CONTROL: 0x00000007
<7> [549.456190] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [549.456614] [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [549.456878] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
<7> [552.991584] [drm:intel_power_well_enable [i915]] enabling DC off
<7> [552.992030] [drm:gen9_set_dc_state [i915]] Setting DC state from 02 to 00
<7> [584.696338] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [584.696707] [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [584.696973] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
<7> [585.271675] [drm:intel_power_well_enable [i915]] enabling DC off
<7> [585.272123] [drm:gen9_set_dc_state [i915]] Setting DC state from 02 to 00
<7> [588.664287] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [588.664571] [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [588.664768] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
Comment 1 Chris Wilson 2018-11-28 12:46:54 UTC
Have you tried pressing the turbo button?
Comment 2 Chris Wilson 2018-11-28 13:12:48 UTC
When it doesn't timeout it takes skl 467s:

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5212/shard-skl7/igt@gem_userptr_blits@readonly-unsync.html

In contrast, apl takes 223s.
Comment 3 Martin Peres 2018-11-30 13:17:40 UTC
(In reply to Chris Wilson from comment #2)
> When it doesn't timeout it takes skl 467s:
> 
> https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5212/shard-skl7/
> igt@gem_userptr_blits@readonly-unsync.html
> 
> In contrast, apl takes 223s.

Both times are pretty extreme :o Are we trying too hard? Could we have a time-based execution as opposed to a fixed load?
Comment 4 Martin Peres 2018-12-03 13:23:18 UTC
Also seen on KBL: https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5235/shard-kbl1/igt@gem_userptr_blits@readonly-unsync.html

<6> [137.288055] Console: switching to colour dummy device 80x25
<6> [137.288167] [IGT] gem_userptr_blits: executing
<6> [137.293130] [IGT] gem_userptr_blits: starting subtest readonly-unsync
Comment 5 Martin Peres 2018-12-17 17:19:59 UTC
Also seen on ICL: https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5311/shard-iclb7/igt@gem_userptr_blits@readonly-unsync.html

<6> [724.273516] Console: switching to colour dummy device 80x25
<6> [724.273572] [IGT] gem_userptr_blits: executing
<6> [724.289708] [IGT] gem_userptr_blits: starting subtest readonly-unsync
<7> [727.244077] [drm:edp_panel_vdd_off_sync [i915]] Turning eDP port A VDD off
<7> [727.244222] [drm:edp_panel_vdd_off_sync [i915]] PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067
<7> [727.244249] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [727.244278] [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [727.244302] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
<7> [733.196137] missed_breadcrumb rcs0 missed breadcrumb at intel_breadcrumbs_hangcheck+0x51/0x70 [i915]
<7> [733.196199] missed_breadcrumb 	current seqno 8001, last 8002, hangcheck 8001 [4032 ms]
<7> [733.196216] missed_breadcrumb 	Reset count: 6 (global 12)
<7> [733.196232] missed_breadcrumb 	Requests:
<7> [733.196256] missed_breadcrumb 		first  8002 [25d9:8002] prio=3 @ 3772ms: gem_userptr_bli[2834]/0
<7> [733.196280] missed_breadcrumb 		last   8002 [25d9:8002] prio=3 @ 3772ms: gem_userptr_bli[2834]/0
<7> [733.196303] missed_breadcrumb 		active 8002 [25d9:8002] prio=3 @ 3772ms: gem_userptr_bli[2834]/0
<7> [733.196313] missed_breadcrumb 		ring->start:  0x007f4000
<7> [733.196327] missed_breadcrumb 		ring->head:   0x00001c00
<7> [733.196335] missed_breadcrumb 		ring->tail:   0x00001c90
<7> [733.196343] missed_breadcrumb 		ring->emit:   0x00001c98
<7> [733.196352] missed_breadcrumb 		ring->space:  0x00002408
<7> [733.196364] missed_breadcrumb [head 1c28, postfix 1c70, tail 1c98, batch 0x00000000_80015000]:
<7> [733.196424] missed_breadcrumb [0000] 7a000004 01144c1c fffff080 00000000 00000000 00000000 04000001 18800101
<7> [733.196448] missed_breadcrumb [0020] 80015000 00000000 04000000 00000000 7a000004 001010a1 fffff080 00000000
<7> [733.196472] missed_breadcrumb [0040] 00000000 00000000 7a000004 01104000 fffe00c0 00000000 00008002 00000000
<7> [733.196490] missed_breadcrumb [0060] 01000000 04000001 02800000 00000000
<7> [733.196544] missed_breadcrumb 	RING_START: 0x007f4000
<7> [733.196559] missed_breadcrumb 	RING_HEAD:  0x00001c50
<7> [733.196573] missed_breadcrumb 	RING_TAIL:  0x00001c90
<7> [733.196596] missed_breadcrumb 	RING_CTL:   0x00003001
<7> [733.196614] missed_breadcrumb 	RING_MODE:  0x00000000
<7> [733.196628] missed_breadcrumb 	RING_IMR: 00000000
<7> [733.196649] missed_breadcrumb 	ACTHD:  0x00000000_80015230
<7> [733.196674] missed_breadcrumb 	BBADDR: 0x00000000_80015231
<7> [733.196694] missed_breadcrumb 	DMA_FADDR: 0x00000000_80015400
<7> [733.196708] missed_breadcrumb 	IPEIR: 0x00000000
<7> [733.196721] missed_breadcrumb 	IPEHR: 0x10000002
<7> [733.196743] missed_breadcrumb 	Execlist status: 0x00001098 00000040
<7> [733.196760] missed_breadcrumb 	Execlist CSB read 5, write 5 [mmio:5], tasklet queued? no (enabled)
<7> [733.196778] missed_breadcrumb 		ELSP[0] count=1, ring->start=007f4000, rq: 8002 [25d9:8002] prio=3 @ 3772ms: gem_userptr_bli[2834]/0
<7> [733.196788] missed_breadcrumb 		ELSP[1] idle
<7> [733.196798] missed_breadcrumb 		HW active? 0x5
<7> [733.196815] missed_breadcrumb 		E 8002 [25d9:8002] prio=3 @ 3772ms: gem_userptr_bli[2834]/0
<7> [733.196827] missed_breadcrumb 		Queue priority: -2147483648
<7> [733.196841] missed_breadcrumb 	gem_userptr_bli [2835:S] waiting for 8002
<7> [733.196853] missed_breadcrumb IRQ? 0x1 (breadcrumbs? yes)
<7> [733.196862] missed_breadcrumb HWSP:
<7> [733.196885] missed_breadcrumb [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [733.196898] missed_breadcrumb *
<7> [733.196916] missed_breadcrumb [0040] 10000018 00000040 10000001 00000000 10000018 00000040 10000001 00000000
<7> [733.196932] missed_breadcrumb [0060] 10000018 00000040 10000001 00000000 00000000 00000000 00000000 00000000
<7> [733.196948] missed_breadcrumb [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [733.196964] missed_breadcrumb [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000005
<7> [733.196977] missed_breadcrumb [00c0] 00008001 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [733.196993] missed_breadcrumb [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [733.197002] missed_breadcrumb *
<7> [733.197014] missed_breadcrumb Idle? no
<7> [735.180041] hangcheck rcs0
<7> [735.180050] hangcheck 	current seqno 8001, last 8002, hangcheck 8001 [6016 ms]
<7> [735.180055] hangcheck 	Reset count: 6 (global 12)
<7> [735.180077] hangcheck 	Requests:
<7> [735.180116] hangcheck 		first  8002 [25d9:8002] prio=3 @ 5756ms: gem_userptr_bli[2834]/0
<7> [735.180122] hangcheck 		last   8002 [25d9:8002] prio=3 @ 5756ms: gem_userptr_bli[2834]/0
<7> [735.180206] hangcheck 		active 8002 [25d9:8002] prio=3 @ 5756ms: gem_userptr_bli[2834]/0
<7> [735.180211] hangcheck 		ring->start:  0x007f4000
<7> [735.180216] hangcheck 		ring->head:   0x00001c00
<7> [735.180221] hangcheck 		ring->tail:   0x00001c90
<7> [735.180225] hangcheck 		ring->emit:   0x00001c98
<7> [735.180230] hangcheck 		ring->space:  0x00002408
<7> [735.180237] hangcheck [head 1c28, postfix 1c70, tail 1c98, batch 0x00000000_80015000]:
<7> [735.180277] hangcheck [0000] 7a000004 01144c1c fffff080 00000000 00000000 00000000 04000001 18800101
<7> [735.180287] hangcheck [0020] 80015000 00000000 04000000 00000000 7a000004 001010a1 fffff080 00000000
<7> [735.180295] hangcheck [0040] 00000000 00000000 7a000004 01104000 fffe00c0 00000000 00008002 00000000
<7> [735.180302] hangcheck [0060] 01000000 04000001 02800000 00000000
<7> [735.180324] hangcheck 	RING_START: 0x007f4000
<7> [735.180331] hangcheck 	RING_HEAD:  0x00001c50
<7> [735.180337] hangcheck 	RING_TAIL:  0x00001c90
<7> [735.180346] hangcheck 	RING_CTL:   0x00003001
<7> [735.180355] hangcheck 	RING_MODE:  0x00000000
<7> [735.180362] hangcheck 	RING_IMR: 00000000
<7> [735.180374] hangcheck 	ACTHD:  0x00000000_80015230
<7> [735.180385] hangcheck 	BBADDR: 0x00000000_80015231
<7> [735.180397] hangcheck 	DMA_FADDR: 0x00000000_80015400
<7> [735.180403] hangcheck 	IPEIR: 0x00000000
<7> [735.180410] hangcheck 	IPEHR: 0x10000002
<7> [735.180419] hangcheck 	Execlist status: 0x00001098 00000040
<7> [735.180427] hangcheck 	Execlist CSB read 5, write 5 [mmio:5], tasklet queued? no (enabled)
<7> [735.180436] hangcheck 		ELSP[0] count=1, ring->start=007f4000, rq: 8002 [25d9:8002] prio=3 @ 5756ms: gem_userptr_bli[2834]/0
<7> [735.180441] hangcheck 		ELSP[1] idle
<7> [735.180445] hangcheck 		HW active? 0x5
<7> [735.180518] hangcheck 		E 8002 [25d9:8002] prio=3 @ 5756ms: gem_userptr_bli[2834]/0
<7> [735.180595] hangcheck 		Queue priority: -2147483648
<7> [735.180682] hangcheck 	gem_userptr_bli [2835:S] waiting for 8002
<7> [735.180760] hangcheck IRQ? 0x1 (breadcrumbs? yes)
<7> [735.180764] hangcheck HWSP:
<7> [735.180772] hangcheck [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [735.180776] hangcheck *
<7> [735.180784] hangcheck [0040] 10000018 00000040 10000001 00000000 10000018 00000040 10000001 00000000
<7> [735.180791] hangcheck [0060] 10000018 00000040 10000001 00000000 00000000 00000000 00000000 00000000
<7> [735.180798] hangcheck [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [735.180806] hangcheck [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000005
<7> [735.180813] hangcheck [00c0] 00008001 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [735.180820] hangcheck [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [735.180824] hangcheck *
<7> [735.180829] hangcheck Idle? no
<7> [735.182333] [drm:i915_reset_device [i915]] resetting chip
<5> [735.182874] i915 0000:00:02.0: Resetting chip for hang on rcs0
<7> [735.183466] [drm:i915_gem_reset_engine [i915]] client gem_userptr_bli[2834]/0: gained 1 ban score, now 1
<7> [739.212118] missed_breadcrumb rcs0 missed breadcrumb at intel_breadcrumbs_hangcheck+0x51/0x70 [i915]
<7> [739.212141] missed_breadcrumb 	current seqno 8003, last 8004, hangcheck 8003 [2048 ms]
<7> [739.212149] missed_breadcrumb 	Reset count: 6 (global 13)
<7> [739.212157] missed_breadcrumb 	Requests:
<7> [739.212170] missed_breadcrumb 		first  8004 [25d9:8004] prio=3 @ 4025ms: gem_userptr_bli[2834]/0
<7> [739.212180] missed_breadcrumb 		last   8004 [25d9:8004] prio=3 @ 4025ms: gem_userptr_bli[2834]/0
<7> [739.212190] missed_breadcrumb 		active 8004 [25d9:8004] prio=3 @ 4025ms: gem_userptr_bli[2834]/0
<7> [739.212198] missed_breadcrumb 		ring->start:  0x007f4000
<7> [739.212205] missed_breadcrumb 		ring->head:   0x00001ce0
<7> [739.212211] missed_breadcrumb 		ring->tail:   0x00001d70
<7> [739.212218] missed_breadcrumb 		ring->emit:   0x00001d78
<7> [739.212225] missed_breadcrumb 		ring->space:  0x00003eb8
<7> [739.212234] missed_breadcrumb [head 1d08, postfix 1d50, tail 1d78, batch 0x00000000_8001a000]:
<7> [739.212281] missed_breadcrumb [0000] 7a000004 01144c1c fffff080 00000000 00000000 00000000 04000001 18800101
<7> [739.212299] missed_breadcrumb [0020] 8001a000 00000000 04000000 00000000 7a000004 001010a1 fffff080 00000000
<7> [739.212316] missed_breadcrumb [0040] 00000000 00000000 7a000004 01104000 fffe00c0 00000000 00008004 00000000
<7> [739.212326] missed_breadcrumb [0060] 01000000 04000001 02800000 00000000
<7> [739.212374] missed_breadcrumb 	RING_START: 0x007f4000
<7> [739.212384] missed_breadcrumb 	RING_HEAD:  0x00001d30
<7> [739.212393] missed_breadcrumb 	RING_TAIL:  0x00001d70
<7> [739.212409] missed_breadcrumb 	RING_CTL:   0x00003001
<7> [739.212426] missed_breadcrumb 	RING_MODE:  0x00000000
<7> [739.212436] missed_breadcrumb 	RING_IMR: 00000000
<7> [739.212455] missed_breadcrumb 	ACTHD:  0x00000000_8001a240
<7> [739.212471] missed_breadcrumb 	BBADDR: 0x00000000_8001a241
<7> [739.212487] missed_breadcrumb 	DMA_FADDR: 0x00000000_8001a440
<7> [739.212496] missed_breadcrumb 	IPEIR: 0x00000000
<7> [739.212506] missed_breadcrumb 	IPEHR: 0x10000002
<7> [739.212520] missed_breadcrumb 	Execlist status: 0x00001098 00000040
<7> [739.212532] missed_breadcrumb 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [739.212546] missed_breadcrumb 		ELSP[0] count=1, ring->start=007f4000, rq: 8004 [25d9:8004] prio=3 @ 4025ms: gem_userptr_bli[2834]/0
<7> [739.212554] missed_breadcrumb 		ELSP[1] idle
<7> [739.212562] missed_breadcrumb 		HW active? 0x5
<7> [739.212574] missed_breadcrumb 		E 8004 [25d9:8004] prio=3 @ 4025ms: gem_userptr_bli[2834]/0
<7> [739.212583] missed_breadcrumb 		Queue priority: -2147483648
<7> [739.212594] missed_breadcrumb 	gem_userptr_bli [2835:S] waiting for 8004
<7> [739.212602] missed_breadcrumb IRQ? 0x1 (breadcrumbs? yes)
<7> [739.212609] missed_breadcrumb HWSP:
<7> [739.212621] missed_breadcrumb [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [739.212628] missed_breadcrumb *
<7> [739.212641] missed_breadcrumb [0040] 10000001 00000000 10000018 00000040 10000001 00000000 10000018 00000040
<7> [739.212653] missed_breadcrumb [0060] 10000001 00000000 10000001 00000000 00000000 00000000 00000000 00000000
<7> [739.212665] missed_breadcrumb [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [739.212676] missed_breadcrumb [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [739.212688] missed_breadcrumb [00c0] 00008003 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [739.212700] missed_breadcrumb [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [739.212706] missed_breadcrumb *
<7> [739.212714] missed_breadcrumb Idle? no
<7> [743.180067] hangcheck rcs0
<7> [743.180076] hangcheck 	current seqno 8003, last 8004, hangcheck 8003 [6016 ms]
<7> [743.180082] hangcheck 	Reset count: 6 (global 13)
<7> [743.180087] hangcheck 	Requests:
<7> [743.180096] hangcheck 		first  8004 [25d9:8004] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [743.180103] hangcheck 		last   8004 [25d9:8004] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [743.180110] hangcheck 		active 8004 [25d9:8004] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [743.180115] hangcheck 		ring->start:  0x007f4000
<7> [743.180120] hangcheck 		ring->head:   0x00001ce0
<7> [743.180124] hangcheck 		ring->tail:   0x00001d70
<7> [743.180129] hangcheck 		ring->emit:   0x00001d78
<7> [743.180134] hangcheck 		ring->space:  0x00003eb8
<7> [743.180140] hangcheck [head 1d08, postfix 1d50, tail 1d78, batch 0x00000000_8001a000]:
<7> [743.180178] hangcheck [0000] 7a000004 01144c1c fffff080 00000000 00000000 00000000 04000001 18800101
<7> [743.180186] hangcheck [0020] 8001a000 00000000 04000000 00000000 7a000004 001010a1 fffff080 00000000
<7> [743.180194] hangcheck [0040] 00000000 00000000 7a000004 01104000 fffe00c0 00000000 00008004 00000000
<7> [743.180201] hangcheck [0060] 01000000 04000001 02800000 00000000
<7> [743.180217] hangcheck 	RING_START: 0x007f4000
<7> [743.180224] hangcheck 	RING_HEAD:  0x00001d30
<7> [743.180230] hangcheck 	RING_TAIL:  0x00001d70
<7> [743.180241] hangcheck 	RING_CTL:   0x00003001
<7> [743.180259] hangcheck 	RING_MODE:  0x00000000
<7> [743.180268] hangcheck 	RING_IMR: 00000000
<7> [743.180279] hangcheck 	ACTHD:  0x00000000_8001a240
<7> [743.180291] hangcheck 	BBADDR: 0x00000000_8001a241
<7> [743.180303] hangcheck 	DMA_FADDR: 0x00000000_8001a440
<7> [743.180309] hangcheck 	IPEIR: 0x00000000
<7> [743.180316] hangcheck 	IPEHR: 0x10000002
<7> [743.180325] hangcheck 	Execlist status: 0x00001098 00000040
<7> [743.180342] hangcheck 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [743.180350] hangcheck 		ELSP[0] count=1, ring->start=007f4000, rq: 8004 [25d9:8004] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [743.180355] hangcheck 		ELSP[1] idle
<7> [743.180360] hangcheck 		HW active? 0x5
<7> [743.180368] hangcheck 		E 8004 [25d9:8004] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [743.180376] hangcheck 		Queue priority: -2147483648
<7> [743.180383] hangcheck 	gem_userptr_bli [2835:S] waiting for 8004
<7> [743.180388] hangcheck IRQ? 0x1 (breadcrumbs? yes)
<7> [743.180392] hangcheck HWSP:
<7> [743.180400] hangcheck [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [743.180404] hangcheck *
<7> [743.180412] hangcheck [0040] 10000001 00000000 10000018 00000040 10000001 00000000 10000018 00000040
<7> [743.180419] hangcheck [0060] 10000001 00000000 10000001 00000000 00000000 00000000 00000000 00000000
<7> [743.180426] hangcheck [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [743.180433] hangcheck [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [743.180440] hangcheck [00c0] 00008003 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [743.180447] hangcheck [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [743.180451] hangcheck *
<7> [743.180456] hangcheck Idle? no
<7> [743.180781] [drm:i915_reset_device [i915]] resetting chip
<5> [743.180894] i915 0000:00:02.0: Resetting chip for hang on rcs0
<7> [743.181174] [drm:i915_gem_reset_engine [i915]] client gem_userptr_bli[2834]/0: gained 1 ban score, now 2
<7> [747.212149] missed_breadcrumb vcs0 missed breadcrumb at intel_breadcrumbs_hangcheck+0x51/0x70 [i915]
<7> [747.212161] missed_breadcrumb 	current seqno 3, last 4, hangcheck 3 [2048 ms]
<7> [747.212167] missed_breadcrumb 	Reset count: 0 (global 14)
<7> [747.212173] missed_breadcrumb 	Requests:
<7> [747.212184] missed_breadcrumb 		first  4 [25da:2] prio=3 @ 4027ms: gem_userptr_bli[2834]/0
<7> [747.212191] missed_breadcrumb 		last   4 [25da:2] prio=3 @ 4027ms: gem_userptr_bli[2834]/0
<7> [747.212200] missed_breadcrumb 		active 4 [25da:2] prio=3 @ 4027ms: gem_userptr_bli[2834]/0
<7> [747.212206] missed_breadcrumb 		ring->start:  0x007f8000
<7> [747.212212] missed_breadcrumb 		ring->head:   0x00000038
<7> [747.212217] missed_breadcrumb 		ring->tail:   0x000000a8
<7> [747.212222] missed_breadcrumb 		ring->emit:   0x000000b0
<7> [747.212228] missed_breadcrumb 		ring->space:  0x00003f10
<7> [747.212237] missed_breadcrumb [head 0058, postfix 0090, tail 00b0, batch 0x00000000_80015000]:
<7> [747.212273] missed_breadcrumb [0000] 13244082 00000104 00000000 00000000 04000001 18800101 80015000 00000000
<7> [747.212283] missed_breadcrumb [0020] 04000000 00000000 13204002 00000104 00000000 00000000 13004002 fffd20c4
<7> [747.212291] missed_breadcrumb [0040] 00000000 00000004 01000000 04000001 02800000 00000000
<7> [747.212324] missed_breadcrumb 	RING_START: 0x007f8000
<7> [747.212333] missed_breadcrumb 	RING_HEAD:  0x00000078
<7> [747.212340] missed_breadcrumb 	RING_TAIL:  0x000000a8
<7> [747.212350] missed_breadcrumb 	RING_CTL:   0x00003001
<7> [747.212360] missed_breadcrumb 	RING_MODE:  0x00000000
<7> [747.212368] missed_breadcrumb 	RING_IMR: 00000000
<7> [747.212381] missed_breadcrumb 	ACTHD:  0x00000000_80015170
<7> [747.212394] missed_breadcrumb 	BBADDR: 0x00000000_80015171
<7> [747.212407] missed_breadcrumb 	DMA_FADDR: 0x00000000_80015340
<7> [747.212414] missed_breadcrumb 	IPEIR: 0x00000000
<7> [747.212422] missed_breadcrumb 	IPEHR: 0x10000002
<7> [747.212432] missed_breadcrumb 	Execlist status: 0x00001098 20000040
<7> [747.212442] missed_breadcrumb 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [747.212452] missed_breadcrumb 		ELSP[0] count=1, ring->start=007f8000, rq: 4 [25da:2] prio=3 @ 4027ms: gem_userptr_bli[2834]/0
<7> [747.212458] missed_breadcrumb 		ELSP[1] idle
<7> [747.212464] missed_breadcrumb 		HW active? 0x5
<7> [747.212475] missed_breadcrumb 		E 4 [25da:2] prio=3 @ 4027ms: gem_userptr_bli[2834]/0
<7> [747.212482] missed_breadcrumb 		Queue priority: -2147483648
<7> [747.212491] missed_breadcrumb 	gem_userptr_bli [2835:S] waiting for 4
<7> [747.212499] missed_breadcrumb IRQ? 0x1 (breadcrumbs? yes)
<7> [747.212504] missed_breadcrumb HWSP:
<7> [747.212514] missed_breadcrumb [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [747.212520] missed_breadcrumb *
<7> [747.212530] missed_breadcrumb [0040] 00000001 20000000 00000018 20000000 00000001 20000000 00000018 20000040
<7> [747.212540] missed_breadcrumb [0060] 00000001 20000000 00000018 20000000 00000000 00000000 00000000 00000000
<7> [747.212550] missed_breadcrumb [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [747.212559] missed_breadcrumb [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [747.212569] missed_breadcrumb [00c0] 00000003 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [747.212578] missed_breadcrumb [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [747.212583] missed_breadcrumb *
<7> [747.212590] missed_breadcrumb Idle? no
<7> [749.197156] hangcheck vcs0
<7> [749.197168] hangcheck 	current seqno 3, last 4, hangcheck 3 [4033 ms]
<7> [749.197175] hangcheck 	Reset count: 0 (global 14)
<7> [749.197183] hangcheck 	Requests:
<7> [749.197195] hangcheck 		first  4 [25da:2] prio=3 @ 6012ms: gem_userptr_bli[2834]/0
<7> [749.197204] hangcheck 		last   4 [25da:2] prio=3 @ 6012ms: gem_userptr_bli[2834]/0
<7> [749.197214] hangcheck 		active 4 [25da:2] prio=3 @ 6012ms: gem_userptr_bli[2834]/0
<7> [749.197222] hangcheck 		ring->start:  0x007f8000
<7> [749.197228] hangcheck 		ring->head:   0x00000038
<7> [749.197235] hangcheck 		ring->tail:   0x000000a8
<7> [749.197241] hangcheck 		ring->emit:   0x000000b0
<7> [749.197248] hangcheck 		ring->space:  0x00003f10
<7> [749.197257] hangcheck [head 0058, postfix 0090, tail 00b0, batch 0x00000000_80015000]:
<7> [749.197295] hangcheck [0000] 13244082 00000104 00000000 00000000 04000001 18800101 80015000 00000000
<7> [749.197306] hangcheck [0020] 04000000 00000000 13204002 00000104 00000000 00000000 13004002 fffd20c4
<7> [749.197315] hangcheck [0040] 00000000 00000004 01000000 04000001 02800000 00000000
<7> [749.197338] hangcheck 	RING_START: 0x007f8000
<7> [749.197347] hangcheck 	RING_HEAD:  0x00000078
<7> [749.197356] hangcheck 	RING_TAIL:  0x000000a8
<7> [749.197368] hangcheck 	RING_CTL:   0x00003001
<7> [749.197379] hangcheck 	RING_MODE:  0x00000000
<7> [749.197388] hangcheck 	RING_IMR: 00000000
<7> [749.197403] hangcheck 	ACTHD:  0x00000000_80015170
<7> [749.197417] hangcheck 	BBADDR: 0x00000000_80015171
<7> [749.197432] hangcheck 	DMA_FADDR: 0x00000000_80015340
<7> [749.197441] hangcheck 	IPEIR: 0x00000000
<7> [749.197450] hangcheck 	IPEHR: 0x10000002
<7> [749.197462] hangcheck 	Execlist status: 0x00001098 20000040
<7> [749.197473] hangcheck 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [749.197485] hangcheck 		ELSP[0] count=1, ring->start=007f8000, rq: 4 [25da:2] prio=3 @ 6012ms: gem_userptr_bli[2834]/0
<7> [749.197492] hangcheck 		ELSP[1] idle
<7> [749.197498] hangcheck 		HW active? 0x5
<7> [749.197509] hangcheck 		E 4 [25da:2] prio=3 @ 6012ms: gem_userptr_bli[2834]/0
<7> [749.197516] hangcheck 		Queue priority: -2147483648
<7> [749.197526] hangcheck 	gem_userptr_bli [2835:S] waiting for 4
<7> [749.197533] hangcheck IRQ? 0x1 (breadcrumbs? yes)
<7> [749.197539] hangcheck HWSP:
<7> [749.197549] hangcheck [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [749.197555] hangcheck *
<7> [749.197566] hangcheck [0040] 00000001 20000000 00000018 20000000 00000001 20000000 00000018 20000040
<7> [749.197576] hangcheck [0060] 00000001 20000000 00000018 20000000 00000000 00000000 00000000 00000000
<7> [749.197585] hangcheck [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [749.197595] hangcheck [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [749.197604] hangcheck [00c0] 00000003 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [749.197614] hangcheck [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [749.197619] hangcheck *
<7> [749.197626] hangcheck Idle? no
<7> [749.198084] [drm:i915_reset_device [i915]] resetting chip
<5> [749.198265] i915 0000:00:02.0: Resetting chip for hang on vcs0
<7> [749.198727] [drm:i915_gem_reset_engine [i915]] client gem_userptr_bli[2834]/0: gained 1 ban score, now 3
<7> [753.164154] missed_breadcrumb bcs0 missed breadcrumb at intel_breadcrumbs_hangcheck+0x51/0x70 [i915]
<7> [753.164212] missed_breadcrumb 	current seqno 4, last 5, hangcheck 4 [1984 ms]
<7> [753.164229] missed_breadcrumb 	Reset count: 0 (global 15)
<7> [753.164245] missed_breadcrumb 	Requests:
<7> [753.164261] missed_breadcrumb 		first  5 [25db:2] prio=3 @ 3961ms: gem_userptr_bli[2834]/0
<7> [753.164275] missed_breadcrumb 		last   5 [25db:2] prio=3 @ 3961ms: gem_userptr_bli[2834]/0
<7> [753.164297] missed_breadcrumb 		active 5 [25db:2] prio=3 @ 3961ms: gem_userptr_bli[2834]/0
<7> [753.164307] missed_breadcrumb 		ring->start:  0x007fc000
<7> [753.164324] missed_breadcrumb 		ring->head:   0x00000038
<7> [753.164340] missed_breadcrumb 		ring->tail:   0x000000a8
<7> [753.164359] missed_breadcrumb 		ring->emit:   0x000000b0
<7> [753.164374] missed_breadcrumb 		ring->space:  0x00003f10
<7> [753.164392] missed_breadcrumb [head 0058, postfix 0090, tail 00b0, batch 0x00000000_8001a000]:
<7> [753.164462] missed_breadcrumb [0000] 13244002 00000104 00000000 00000000 04000001 18800101 8001a000 00000000
<7> [753.164481] missed_breadcrumb [0020] 04000000 00000000 13204002 00000104 00000000 00000000 13004002 fffd90c4
<7> [753.164498] missed_breadcrumb [0040] 00000000 00000005 01000000 04000001 02800000 00000000
<7> [753.164538] missed_breadcrumb 	RING_START: 0x007fc000
<7> [753.164551] missed_breadcrumb 	RING_HEAD:  0x00000078
<7> [753.164566] missed_breadcrumb 	RING_TAIL:  0x000000a8
<7> [753.164584] missed_breadcrumb 	RING_CTL:   0x00003001
<7> [753.164608] missed_breadcrumb 	RING_MODE:  0x00000000
<7> [753.164634] missed_breadcrumb 	RING_IMR: 00000000
<7> [753.164661] missed_breadcrumb 	ACTHD:  0x00000000_8001a0c0
<7> [753.164680] missed_breadcrumb 	BBADDR: 0x00000000_8001a0c1
<7> [753.164700] missed_breadcrumb 	DMA_FADDR: 0x00000000_8001a2c0
<7> [753.164714] missed_breadcrumb 	IPEIR: 0x00000000
<7> [753.164728] missed_breadcrumb 	IPEHR: 0x10000002
<7> [753.164746] missed_breadcrumb 	Execlist status: 0x00001098 60000040
<7> [753.164771] missed_breadcrumb 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [753.164796] missed_breadcrumb 		ELSP[0] count=1, ring->start=007fc000, rq: 5 [25db:2] prio=3 @ 3961ms: gem_userptr_bli[2834]/0
<7> [753.164808] missed_breadcrumb 		ELSP[1] idle
<7> [753.164819] missed_breadcrumb 		HW active? 0x5
<7> [753.164836] missed_breadcrumb 		E 5 [25db:2] prio=3 @ 3961ms: gem_userptr_bli[2834]/0
<7> [753.164848] missed_breadcrumb 		Queue priority: -2147483648
<7> [753.164870] missed_breadcrumb 	gem_userptr_bli [2835:R] waiting for 5
<7> [753.164893] missed_breadcrumb IRQ? 0x1 (breadcrumbs? yes)
<7> [753.164905] missed_breadcrumb HWSP:
<7> [753.164923] missed_breadcrumb [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [753.164933] missed_breadcrumb *
<7> [753.164952] missed_breadcrumb [0040] 00000001 60000000 00000018 60000000 00000001 60000000 00000018 60000040
<7> [753.164969] missed_breadcrumb [0060] 00000001 60000000 00000001 60000000 00000000 00000000 00000000 00000000
<7> [753.164987] missed_breadcrumb [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [753.165006] missed_breadcrumb [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [753.165029] missed_breadcrumb [00c0] 00000004 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [753.165053] missed_breadcrumb [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [753.165070] missed_breadcrumb *
<7> [753.165084] missed_breadcrumb Idle? no
<7> [755.148085] hangcheck bcs0
<7> [755.148096] hangcheck 	current seqno 4, last 5, hangcheck 4 [3968 ms]
<7> [755.148103] hangcheck 	Reset count: 0 (global 15)
<7> [755.148109] hangcheck 	Requests:
<7> [755.148120] hangcheck 		first  5 [25db:2] prio=3 @ 5945ms: gem_userptr_bli[2834]/0
<7> [755.148128] hangcheck 		last   5 [25db:2] prio=3 @ 5945ms: gem_userptr_bli[2834]/0
<7> [755.148137] hangcheck 		active 5 [25db:2] prio=3 @ 5945ms: gem_userptr_bli[2834]/0
<7> [755.148144] hangcheck 		ring->start:  0x007fc000
<7> [755.148150] hangcheck 		ring->head:   0x00000038
<7> [755.148155] hangcheck 		ring->tail:   0x000000a8
<7> [755.148161] hangcheck 		ring->emit:   0x000000b0
<7> [755.148167] hangcheck 		ring->space:  0x00003f10
<7> [755.148174] hangcheck [head 0058, postfix 0090, tail 00b0, batch 0x00000000_8001a000]:
<7> [755.148205] hangcheck [0000] 13244002 00000104 00000000 00000000 04000001 18800101 8001a000 00000000
<7> [755.148215] hangcheck [0020] 04000000 00000000 13204002 00000104 00000000 00000000 13004002 fffd90c4
<7> [755.148224] hangcheck [0040] 00000000 00000005 01000000 04000001 02800000 00000000
<7> [755.148243] hangcheck 	RING_START: 0x007fc000
<7> [755.148251] hangcheck 	RING_HEAD:  0x00000078
<7> [755.148259] hangcheck 	RING_TAIL:  0x000000a8
<7> [755.148269] hangcheck 	RING_CTL:   0x00003001
<7> [755.148280] hangcheck 	RING_MODE:  0x00000000
<7> [755.148287] hangcheck 	RING_IMR: 00000000
<7> [755.148300] hangcheck 	ACTHD:  0x00000000_8001a0c0
<7> [755.148313] hangcheck 	BBADDR: 0x00000000_8001a0c1
<7> [755.148326] hangcheck 	DMA_FADDR: 0x00000000_8001a2c0
<7> [755.148334] hangcheck 	IPEIR: 0x00000000
<7> [755.148342] hangcheck 	IPEHR: 0x10000002
<7> [755.148352] hangcheck 	Execlist status: 0x00001098 60000040
<7> [755.148362] hangcheck 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [755.148372] hangcheck 		ELSP[0] count=1, ring->start=007fc000, rq: 5 [25db:2] prio=3 @ 5945ms: gem_userptr_bli[2834]/0
<7> [755.148379] hangcheck 		ELSP[1] idle
<7> [755.148386] hangcheck 		HW active? 0x5
<7> [755.148396] hangcheck 		E 5 [25db:2] prio=3 @ 5945ms: gem_userptr_bli[2834]/0
<7> [755.148403] hangcheck 		Queue priority: -2147483648
<7> [755.148413] hangcheck 	gem_userptr_bli [2835:S] waiting for 5
<7> [755.148420] hangcheck IRQ? 0x1 (breadcrumbs? yes)
<7> [755.148426] hangcheck HWSP:
<7> [755.148436] hangcheck [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [755.148442] hangcheck *
<7> [755.148452] hangcheck [0040] 00000001 60000000 00000018 60000000 00000001 60000000 00000018 60000040
<7> [755.148462] hangcheck [0060] 00000001 60000000 00000001 60000000 00000000 00000000 00000000 00000000
<7> [755.148471] hangcheck [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [755.148481] hangcheck [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [755.148490] hangcheck [00c0] 00000004 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [755.148500] hangcheck [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [755.148505] hangcheck *
<7> [755.148513] hangcheck Idle? no
<7> [757.196097] hangcheck bcs0
<7> [757.196108] hangcheck 	current seqno 4, last 5, hangcheck 4 [6016 ms]
<7> [757.196114] hangcheck 	Reset count: 0 (global 15)
<7> [757.196120] hangcheck 	Requests:
<7> [757.196130] hangcheck 		first  5 [25db:2] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [757.196139] hangcheck 		last   5 [25db:2] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [757.196147] hangcheck 		active 5 [25db:2] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [757.196154] hangcheck 		ring->start:  0x007fc000
<7> [757.196160] hangcheck 		ring->head:   0x00000038
<7> [757.196165] hangcheck 		ring->tail:   0x000000a8
<7> [757.196171] hangcheck 		ring->emit:   0x000000b0
<7> [757.196177] hangcheck 		ring->space:  0x00003f10
<7> [757.196185] hangcheck [head 0058, postfix 0090, tail 00b0, batch 0x00000000_8001a000]:
<7> [757.196216] hangcheck [0000] 13244002 00000104 00000000 00000000 04000001 18800101 8001a000 00000000
<7> [757.196226] hangcheck [0020] 04000000 00000000 13204002 00000104 00000000 00000000 13004002 fffd90c4
<7> [757.196234] hangcheck [0040] 00000000 00000005 01000000 04000001 02800000 00000000
<7> [757.196254] hangcheck 	RING_START: 0x007fc000
<7> [757.196262] hangcheck 	RING_HEAD:  0x00000078
<7> [757.196270] hangcheck 	RING_TAIL:  0x000000a8
<7> [757.196281] hangcheck 	RING_CTL:   0x00003001
<7> [757.196301] hangcheck 	RING_MODE:  0x00000000
<7> [757.196309] hangcheck 	RING_IMR: 00000000
<7> [757.196323] hangcheck 	ACTHD:  0x00000000_8001a0c0
<7> [757.196340] hangcheck 	BBADDR: 0x00000000_8001a0c1
<7> [757.196360] hangcheck 	DMA_FADDR: 0x00000000_8001a2c0
<7> [757.196369] hangcheck 	IPEIR: 0x00000000
<7> [757.196377] hangcheck 	IPEHR: 0x10000002
<7> [757.196389] hangcheck 	Execlist status: 0x00001098 60000040
<7> [757.196400] hangcheck 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [757.196416] hangcheck 		ELSP[0] count=1, ring->start=007fc000, rq: 5 [25db:2] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [757.196423] hangcheck 		ELSP[1] idle
<7> [757.196429] hangcheck 		HW active? 0x5
<7> [757.196439] hangcheck 		E 5 [25db:2] prio=3 @ 7993ms: gem_userptr_bli[2834]/0
<7> [757.196446] hangcheck 		Queue priority: -2147483648
<7> [757.196455] hangcheck 	gem_userptr_bli [2835:S] waiting for 5
<7> [757.196462] hangcheck IRQ? 0x1 (breadcrumbs? yes)
<7> [757.196468] hangcheck HWSP:
<7> [757.196478] hangcheck [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [757.196484] hangcheck *
<7> [757.196494] hangcheck [0040] 00000001 60000000 00000018 60000000 00000001 60000000 00000018 60000040
<7> [757.196504] hangcheck [0060] 00000001 60000000 00000001 60000000 00000000 00000000 00000000 00000000
<7> [757.196513] hangcheck [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [757.196523] hangcheck [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [757.196532] hangcheck [00c0] 00000004 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [757.196542] hangcheck [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [757.196547] hangcheck *
<7> [757.196554] hangcheck Idle? no
<7> [757.196989] [drm:i915_reset_device [i915]] resetting chip
<5> [757.197229] i915 0000:00:02.0: Resetting chip for hang on bcs0
<7> [757.197613] [drm:i915_gem_reset_engine [i915]] client gem_userptr_bli[2834]/0: gained 1 ban score, now 4
<7> [761.165091] missed_breadcrumb vecs0 missed breadcrumb at intel_breadcrumbs_hangcheck+0x51/0x70 [i915]
<7> [761.165104] missed_breadcrumb 	current seqno 5, last 6, hangcheck 5 [1985 ms]
<7> [761.165111] missed_breadcrumb 	Reset count: 0 (global 16)
<7> [761.165118] missed_breadcrumb 	Requests:
<7> [761.165130] missed_breadcrumb 		first  6 [25dc:2] prio=3 @ 3963ms: gem_userptr_bli[2834]/0
<7> [761.165139] missed_breadcrumb 		last   6 [25dc:2] prio=3 @ 3963ms: gem_userptr_bli[2834]/0
<7> [761.165148] missed_breadcrumb 		active 6 [25dc:2] prio=3 @ 3963ms: gem_userptr_bli[2834]/0
<7> [761.165155] missed_breadcrumb 		ring->start:  0x00800000
<7> [761.165161] missed_breadcrumb 		ring->head:   0x00000038
<7> [761.165168] missed_breadcrumb 		ring->tail:   0x000000a8
<7> [761.165173] missed_breadcrumb 		ring->emit:   0x000000b0
<7> [761.165179] missed_breadcrumb 		ring->space:  0x00003f10
<7> [761.165188] missed_breadcrumb [head 0058, postfix 0090, tail 00b0, batch 0x00000000_80015000]:
<7> [761.165230] missed_breadcrumb [0000] 13244002 00000104 00000000 00000000 04000001 18800101 80015000 00000000
<7> [761.165241] missed_breadcrumb [0020] 04000000 00000000 13204002 00000104 00000000 00000000 13004002 fffc40c4
<7> [761.165250] missed_breadcrumb [0040] 00000000 00000006 01000000 04000001 02800000 00000000
<7> [761.165276] missed_breadcrumb 	RING_START: 0x00800000
<7> [761.165285] missed_breadcrumb 	RING_HEAD:  0x00000078
<7> [761.165293] missed_breadcrumb 	RING_TAIL:  0x000000a8
<7> [761.165304] missed_breadcrumb 	RING_CTL:   0x00003001
<7> [761.165315] missed_breadcrumb 	RING_MODE:  0x00000000
<7> [761.165323] missed_breadcrumb 	RING_IMR: 00000000
<7> [761.165337] missed_breadcrumb 	ACTHD:  0x00000000_80015140
<7> [761.165350] missed_breadcrumb 	BBADDR: 0x00000000_80015141
<7> [761.165364] missed_breadcrumb 	DMA_FADDR: 0x00000000_80015340
<7> [761.165372] missed_breadcrumb 	IPEIR: 0x00000000
<7> [761.165380] missed_breadcrumb 	IPEHR: 0x10000002
<7> [761.165392] missed_breadcrumb 	Execlist status: 0x00001098 40000040
<7> [761.165402] missed_breadcrumb 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [761.165413] missed_breadcrumb 		ELSP[0] count=1, ring->start=00800000, rq: 6 [25dc:2] prio=3 @ 3963ms: gem_userptr_bli[2834]/0
<7> [761.165420] missed_breadcrumb 		ELSP[1] idle
<7> [761.165426] missed_breadcrumb 		HW active? 0x5
<7> [761.165436] missed_breadcrumb 		E 6 [25dc:2] prio=3 @ 3963ms: gem_userptr_bli[2834]/0
<7> [761.165448] missed_breadcrumb 		Queue priority: -2147483648
<7> [761.165458] missed_breadcrumb 	gem_userptr_bli [2835:R] waiting for 6
<7> [761.165465] missed_breadcrumb IRQ? 0x1 (breadcrumbs? yes)
<7> [761.165470] missed_breadcrumb HWSP:
<7> [761.165480] missed_breadcrumb [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [761.165485] missed_breadcrumb *
<7> [761.165496] missed_breadcrumb [0040] 00000001 40000000 00000018 40000000 00000001 40000000 00000018 40000040
<7> [761.165506] missed_breadcrumb [0060] 00000001 40000000 00000001 40000000 00000000 00000000 00000000 00000000
<7> [761.165515] missed_breadcrumb [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [761.165524] missed_breadcrumb [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [761.165534] missed_breadcrumb [00c0] 00000005 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [761.165543] missed_breadcrumb [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [761.165548] missed_breadcrumb *
<7> [761.165555] missed_breadcrumb Idle? no
<7> [763.148248] hangcheck vecs0
<7> [763.148262] hangcheck 	current seqno 5, last 6, hangcheck 5 [3968 ms]
<7> [763.148270] hangcheck 	Reset count: 0 (global 16)
<7> [763.148278] hangcheck 	Requests:
<7> [763.148292] hangcheck 		first  6 [25dc:2] prio=3 @ 5946ms: gem_userptr_bli[2834]/0
<7> [763.148302] hangcheck 		last   6 [25dc:2] prio=3 @ 5946ms: gem_userptr_bli[2834]/0
<7> [763.148314] hangcheck 		active 6 [25dc:2] prio=3 @ 5946ms: gem_userptr_bli[2834]/0
<7> [763.148322] hangcheck 		ring->start:  0x00800000
<7> [763.148329] hangcheck 		ring->head:   0x00000038
<7> [763.148337] hangcheck 		ring->tail:   0x000000a8
<7> [763.148344] hangcheck 		ring->emit:   0x000000b0
<7> [763.148351] hangcheck 		ring->space:  0x00003f10
<7> [763.148361] hangcheck [head 0058, postfix 0090, tail 00b0, batch 0x00000000_80015000]:
<7> [763.148398] hangcheck [0000] 13244002 00000104 00000000 00000000 04000001 18800101 80015000 00000000
<7> [763.148411] hangcheck [0020] 04000000 00000000 13204002 00000104 00000000 00000000 13004002 fffc40c4
<7> [763.148422] hangcheck [0040] 00000000 00000006 01000000 04000001 02800000 00000000
<7> [763.148446] hangcheck 	RING_START: 0x00800000
<7> [763.148456] hangcheck 	RING_HEAD:  0x00000078
<7> [763.148466] hangcheck 	RING_TAIL:  0x000000a8
<7> [763.148479] hangcheck 	RING_CTL:   0x00003001
<7> [763.148491] hangcheck 	RING_MODE:  0x00000000
<7> [763.148501] hangcheck 	RING_IMR: 00000000
<7> [763.148517] hangcheck 	ACTHD:  0x00000000_80015140
<7> [763.148533] hangcheck 	BBADDR: 0x00000000_80015141
<7> [763.148553] hangcheck 	DMA_FADDR: 0x00000000_80015340
<7> [763.148563] hangcheck 	IPEIR: 0x00000000
<7> [763.148572] hangcheck 	IPEHR: 0x10000002
<7> [763.148586] hangcheck 	Execlist status: 0x00001098 40000040
<7> [763.148598] hangcheck 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [763.148611] hangcheck 		ELSP[0] count=1, ring->start=00800000, rq: 6 [25dc:2] prio=3 @ 5946ms: gem_userptr_bli[2834]/0
<7> [763.148619] hangcheck 		ELSP[1] idle
<7> [763.148626] hangcheck 		HW active? 0x5
<7> [763.148638] hangcheck 		E 6 [25dc:2] prio=3 @ 5946ms: gem_userptr_bli[2834]/0
<7> [763.148646] hangcheck 		Queue priority: -2147483648
<7> [763.148657] hangcheck 	gem_userptr_bli [2835:S] waiting for 6
<7> [763.148666] hangcheck IRQ? 0x1 (breadcrumbs? yes)
<7> [763.148673] hangcheck HWSP:
<7> [763.148684] hangcheck [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [763.148691] hangcheck *
<7> [763.148703] hangcheck [0040] 00000001 40000000 00000018 40000000 00000001 40000000 00000018 40000040
<7> [763.148714] hangcheck [0060] 00000001 40000000 00000001 40000000 00000000 00000000 00000000 00000000
<7> [763.148725] hangcheck [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [763.148735] hangcheck [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [763.148746] hangcheck [00c0] 00000005 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [763.148757] hangcheck [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [763.148763] hangcheck *
<7> [763.148771] hangcheck Idle? no
<7> [765.197174] hangcheck vecs0
<7> [765.197187] hangcheck 	current seqno 5, last 6, hangcheck 5 [6017 ms]
<7> [765.197197] hangcheck 	Reset count: 0 (global 16)
<7> [765.197204] hangcheck 	Requests:
<7> [765.197216] hangcheck 		first  6 [25dc:2] prio=3 @ 7995ms: gem_userptr_bli[2834]/0
<7> [765.197225] hangcheck 		last   6 [25dc:2] prio=3 @ 7995ms: gem_userptr_bli[2834]/0
<7> [765.197235] hangcheck 		active 6 [25dc:2] prio=3 @ 7995ms: gem_userptr_bli[2834]/0
<7> [765.197242] hangcheck 		ring->start:  0x00800000
<7> [765.197248] hangcheck 		ring->head:   0x00000038
<7> [765.197255] hangcheck 		ring->tail:   0x000000a8
<7> [765.197261] hangcheck 		ring->emit:   0x000000b0
<7> [765.197267] hangcheck 		ring->space:  0x00003f10
<7> [765.197276] hangcheck [head 0058, postfix 0090, tail 00b0, batch 0x00000000_80015000]:
<7> [765.197309] hangcheck [0000] 13244002 00000104 00000000 00000000 04000001 18800101 80015000 00000000
<7> [765.197320] hangcheck [0020] 04000000 00000000 13204002 00000104 00000000 00000000 13004002 fffc40c4
<7> [765.197329] hangcheck [0040] 00000000 00000006 01000000 04000001 02800000 00000000
<7> [765.197350] hangcheck 	RING_START: 0x00800000
<7> [765.197359] hangcheck 	RING_HEAD:  0x00000078
<7> [765.197368] hangcheck 	RING_TAIL:  0x000000a8
<7> [765.197379] hangcheck 	RING_CTL:   0x00003001
<7> [765.197390] hangcheck 	RING_MODE:  0x00000000
<7> [765.197399] hangcheck 	RING_IMR: 00000000
<7> [765.197413] hangcheck 	ACTHD:  0x00000000_80015140
<7> [765.197427] hangcheck 	BBADDR: 0x00000000_80015141
<7> [765.197442] hangcheck 	DMA_FADDR: 0x00000000_80015340
<7> [765.197450] hangcheck 	IPEIR: 0x00000000
<7> [765.197458] hangcheck 	IPEHR: 0x10000002
<7> [765.197470] hangcheck 	Execlist status: 0x00001098 40000040
<7> [765.197481] hangcheck 	Execlist CSB read 4, write 4 [mmio:4], tasklet queued? no (enabled)
<7> [765.197492] hangcheck 		ELSP[0] count=1, ring->start=00800000, rq: 6 [25dc:2] prio=3 @ 7995ms: gem_userptr_bli[2834]/0
<7> [765.197499] hangcheck 		ELSP[1] idle
<7> [765.197506] hangcheck 		HW active? 0x5
<7> [765.197516] hangcheck 		E 6 [25dc:2] prio=3 @ 7995ms: gem_userptr_bli[2834]/0
<7> [765.197523] hangcheck 		Queue priority: -2147483648
<7> [765.197532] hangcheck 	gem_userptr_bli [2835:S] waiting for 6
<7> [765.197539] hangcheck IRQ? 0x1 (breadcrumbs? yes)
<7> [765.197545] hangcheck HWSP:
<7> [765.197555] hangcheck [0000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [765.197561] hangcheck *
<7> [765.197571] hangcheck [0040] 00000001 40000000 00000018 40000000 00000001 40000000 00000018 40000040
<7> [765.197582] hangcheck [0060] 00000001 40000000 00000001 40000000 00000000 00000000 00000000 00000000
<7> [765.197591] hangcheck [0080] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [765.197601] hangcheck [00a0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000004
<7> [765.197611] hangcheck [00c0] 00000005 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [765.197621] hangcheck [00e0] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<7> [765.197626] hangcheck *
<7> [765.197633] hangcheck Idle? no
<7> [765.197918] [drm:i915_reset_device [i915]] resetting chip
<5> [765.198179] i915 0000:00:02.0: Resetting chip for hang on vecs0
<7> [765.198928] [drm:i915_gem_reset_engine [i915]] context gem_userptr_bli[2834]/0: guilty 5, score 42, banned
<7> [765.199192] [drm:i915_gem_reset_engine [i915]] client gem_userptr_bli[2834]/0: gained 4 ban score, now 8
<6> [1022.348183] kworker/dying (183) used greatest stack depth: 11464 bytes left
Comment 7 Chris Wilson 2019-01-16 11:10:11 UTC
commit 8477ed9aeeaa8afb491d73a4c53d1b7dc64413c6 (upstream/master, origin/master, origin/HEAD)
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Jan 15 20:50:24 2019 +0000

    i915/gem_userptr_blits: Only mlock the memfd once, not the arena
    
    We multiply the memfd 64k to create a 2G arena which we then attempt to
    write into after marking read-only. However, when it comes to unlock the
    arena after the test, performance tanks as the kernel tries to resolve
    the 64k repeated mappings onto the same set of pages. (Must not be a
    very common operation!) We can get away with just mlocking the backing
    store to prevent its eviction, which should prevent the arena mapping
    from being freed as well.
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=108887
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
    Reviewed-by: Mika Kuoppala <mika.kuoppala@linux.intel.com>
Comment 8 CI Bug Log 2019-01-24 15:20:18 UTC
A CI Bug Log filter associated to this bug has been updated:

{- SKL KBL GLK ICL: igt@gem_userptr_blits@readonly-unsync - timeout -}
{+ BDW SKL KBL GLK CFL ICL: igt@gem_userptr_blits@readonly-unsync - timeout +}

New failures caught by the filter:

* https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_177/fi-bdw-gvtdvm/igt@gem_userptr_blits@readonly-unsync.html
* https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_181/fi-cfl-8700k/igt@gem_userptr_blits@readonly-unsync.html
* https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_191/fi-cfl-8700k/igt@gem_userptr_blits@readonly-unsync.html
* https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_188/fi-bdw-gvtdvm/igt@gem_userptr_blits@readonly-unsync.html
Comment 9 Lakshmi 2019-01-24 16:12:56 UTC
(In reply to Chris Wilson from comment #7)
> commit 8477ed9aeeaa8afb491d73a4c53d1b7dc64413c6 (upstream/master,
> origin/master, origin/HEAD)
> Author: Chris Wilson <chris@chris-wilson.co.uk>
> Date:   Tue Jan 15 20:50:24 2019 +0000
> 
>     i915/gem_userptr_blits: Only mlock the memfd once, not the arena
>     
>     We multiply the memfd 64k to create a 2G arena which we then attempt to
>     write into after marking read-only. However, when it comes to unlock the
>     arena after the test, performance tanks as the kernel tries to resolve
>     the 64k repeated mappings onto the same set of pages. (Must not be a
>     very common operation!) We can get away with just mlocking the backing
>     store to prevent its eviction, which should prevent the arena mapping
>     from being freed as well.
>     
>     References: https://bugs.freedesktop.org/show_bug.cgi?id=108887
>     Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
>     Reviewed-by: Mika Kuoppala <mika.kuoppala@linux.intel.com>

Last seen this issue drmtip_196 (5 days, 22 hours / 341 runs ago) on SKL.
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_196/fi-skl-6700k2/igt@gem_userptr_blits@readonly-unsync.html

Are these changes are in drmtip already?
Comment 10 Martin Peres 2019-03-06 18:46:16 UTC
(In reply to Chris Wilson from comment #7)
> commit 8477ed9aeeaa8afb491d73a4c53d1b7dc64413c6 (upstream/master,
> origin/master, origin/HEAD)
> Author: Chris Wilson <chris@chris-wilson.co.uk>
> Date:   Tue Jan 15 20:50:24 2019 +0000
> 
>     i915/gem_userptr_blits: Only mlock the memfd once, not the arena
>     
>     We multiply the memfd 64k to create a 2G arena which we then attempt to
>     write into after marking read-only. However, when it comes to unlock the
>     arena after the test, performance tanks as the kernel tries to resolve
>     the 64k repeated mappings onto the same set of pages. (Must not be a
>     very common operation!) We can get away with just mlocking the backing
>     store to prevent its eviction, which should prevent the arena mapping
>     from being freed as well.
>     
>     References: https://bugs.freedesktop.org/show_bug.cgi?id=108887
>     Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
>     Reviewed-by: Mika Kuoppala <mika.kuoppala@linux.intel.com>

It did the trick, thanks! Closing!
Comment 11 CI Bug Log 2019-03-06 18:46:24 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.