[Intel-gfx] [Linux v4.10.0-rc1+] Still call-traces after suspend-resume (pm? i915? cpu/hotplug?)

Tue Jan 31 13:13:03 UTC 2017

On Tue, Jan 31, 2017 at 01:12:05PM +0100, Rafael J. Wysocki wrote:
> On 1/31/2017 1:02 PM, Imre Deak wrote:
> >On Tue, Jan 31, 2017 at 12:39:35PM +0100, Rafael J. Wysocki wrote:
> >>On 1/31/2017 11:58 AM, Imre Deak wrote:
> >>>Hi Rafael,
> >>Hi,
> >>
> >>>On Mon, Jan 30, 2017 at 11:44:37PM +0100, Rafael J. Wysocki wrote:
> >>>>On 1/24/2017 2:33 AM, Sedat Dilek wrote:
> >>>>>On Fri, Dec 30, 2016 at 3:02 PM, Rafael J. Wysocki <rafael at kernel.org> wrote:
> >>>>>>On Fri, Dec 30, 2016 at 12:40 PM, Sedat Dilek <sedat.dilek at gmail.com> wrote:
> >>>>>>>Hi,
> >>>>>>>
> >>>>>>>I have already reported this issue in [1].
> >>>>>>>One of the issue was solved.
> >>>>>>>Unfortunately, it looks like there is still a different problem here
> >>>>>>>(Ubuntu/precise AMD64).
> >>>>>>>
> >>>>>>>I tried v4.10-rc1 and latest Linus tree up to...
> >>>>>>>
> >>>>>>>commit 98473f9f3f9bd404873cd1178c8be7d6d619f0d1
> >>>>>>>"mm/filemap: fix parameters to test_bit()"
> >>>>>>>
> >>>>>>>Here we go...
> >>>>>>>
> >>>>>>>[   29.636047] BUG: sleeping function called from invalid context at
> >>>>>>>drivers/base/power/runtime.c:1032
> >>>>>>>[   29.636055] in_atomic(): 1, irqs_disabled(): 0, pid: 1500, name: Xorg
> >>>>>>>[   29.636058] 1 lock held by Xorg/1500:
> >>>>>>>[   29.636060]  #0:  (&dev->struct_mutex){+.+.+.}, at:
> >>>>>>>[<ffffffffa0680c13>] i915_mutex_lock_interruptible+0x43/0x140 [i915]
> >>>>>>>[   29.636107] CPU: 0 PID: 1500 Comm: Xorg Not tainted
> >>>>>>>4.10.0-rc1-6-iniza-amd64 #1
> >>>>>>>[   29.636109] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
> >>>>>>>530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
> >>>>>>>[   29.636111] Call Trace:
> >>>>>>>[   29.636120]  dump_stack+0x85/0xc2
> >>>>>>>[   29.636124]  ___might_sleep+0x196/0x260
> >>>>>>>[   29.636127]  __might_sleep+0x53/0xb0
> >>>>>>>[   29.636131]  __pm_runtime_resume+0x7a/0x90
> >>>>>>>[   29.636159]  intel_runtime_pm_get+0x25/0x90 [i915]
> >>>>>>>[   29.636189]  aliasing_gtt_bind_vma+0xaa/0xf0 [i915]
> >>>>>>>[   29.636220]  i915_vma_bind+0xaf/0x1e0 [i915]
> >>>>>>>[   29.636248]  i915_gem_execbuffer_relocate_entry+0x513/0x6f0 [i915]
> >>>>>>>[   29.636272]  i915_gem_execbuffer_relocate_vma.isra.34+0x188/0x250 [i915]
> >>>>>>>[   29.636275]  ? trace_hardirqs_on+0xd/0x10
> >>>>>>>[   29.636294]  ? i915_gem_execbuffer_reserve_vma.isra.31+0x152/0x1f0 [i915]
> >>>>>>>[   29.636316]  ? i915_gem_execbuffer_reserve.isra.32+0x372/0x3a0 [i915]
> >>>>>>>[   29.636342]  i915_gem_do_execbuffer.isra.38+0xa70/0x1a40 [i915]
> >>>>>>>[   29.636347]  ? __might_fault+0x4e/0xb0
> >>>>>>>[   29.636373]  i915_gem_execbuffer2+0xc5/0x260 [i915]
> >>>>>>>[   29.636376]  ? __might_fault+0x4e/0xb0
> >>>>>>>[   29.636395]  drm_ioctl+0x206/0x450 [drm]
> >>>>>>>[   29.636420]  ? i915_gem_execbuffer+0x340/0x340 [i915]
> >>>>>>>[   29.636425]  ? __fget+0x5/0x200
> >>>>>>>[   29.636429]  do_vfs_ioctl+0x91/0x6f0
> >>>>>>>[   29.636431]  ? __fget+0x111/0x200
> >>>>>>>[   29.636433]  ? __fget+0x5/0x200
> >>>>>>>[   29.636436]  SyS_ioctl+0x79/0x90
> >>>>>>>[   29.636441]  entry_SYSCALL_64_fastpath+0x23/0xc6
> >>>>>>>
> >>>>>>>On suspend/resume I see the same call trace.
> >>>>>>>[2] points to the "BUG" line.
> >>>>>>Well, this appears to be an i915 issue, but not a serious one.
> >>>>>>
> >>>>>>Clearly, a function that may sleep (pm_runtime_get_sync() in
> >>>>>>intel_runtime_pm_get()) is called with disabled interrupts.  If I
> >>>>>>understand the code correctly, though, it actually is not going to
> >>>>>>sleep in this particular case, because pm_runtime_get_sync() has
> >>>>>>already been called once for this device in the same code path which
> >>>>>>means that this particular instance will return immediately, so this
> >>>>>>is a false-positive (most likely).
> >>>Not sure what's the root cause, but thought to clarify the above:
> >>>
> >>>Yes, i915_gem_do_execbuffer() does take an RPM reference to optimize
> >>>things, so the RPM get in aliasing_gtt_bind_vma() won't need to resume
> >>>the device on this path. This isn't a guarantee though,
> >>>aliasing_gtt_bind_vma() could be called from other places without an RPM
> >>>reference. So preemption being disabled at that point is not
> >>>intentional. I also can't see where on the above path it would get
> >>>disabled due to a bug or otherwise.
> >>The i915 code is correct AFAICS, but the core complains about a nested
> >>invocation of pm_runtime_get_sync() with disabled interrupts (which looks OK
> >>though), so the complaint is a false positive.
> >Well, my point was that interrupts (or preemption) doesn't seem to get
> >disabled anywhere on that path.
> 
> But the might_sleep_if() assertion in __pm_runtime_resume() triggers for
> some reason.  I wonder why then?
> 
> Of course, I may be overlooking something in the i915 code.
> 
> In any case, if you do
> 
> pm_runtime_get_sync(dev)
> local_irq_disable()
> pm_runtime_get_sync(dev)
> <do something>
> pm_runtime_put(dev)
> local_irq_enable()
> pm_runtime_put(dev)
> 
> that is technically correct, but it will cause the core to complain.

Ah, found it it's the i915 reloc_cache keeping some atomic mappings
around. So moving the warn as you said looks ok, sorry for the noise.

--Imre