Hi Jens,
I'm seeing the lockdep warning below on shutdown on a Power8 machine
using IPR.
If I'm reading it right it looks like the spin_lock() (non-irq) in
blk_mq_sched_insert_request() is the immediate cause.
All the users of ctx->lock should be from process context.
Looking at blk_mq_requeue_work() (the caller), it is doing
spin_lock_irqsave(). So is switching blk_mq_sched_insert_request() to
spin_lock_irqsave() the right fix?
That's because the requeue lock needs to be IRQ safe. However, the
context allows for just spin_lock_irq() for that lock there, so that
should be fixed up. Not your issue, of course, but we don't need to
save flags there.
quoted hunk
ipr 0001:08:00.0: shutdown
================================
WARNING: inconsistent lock state
4.13.0-rc2-gcc6x-gf74c89b #1 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
swapper/28/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
(&(&hctx->lock)->rlock){+.?...}, at: [<c0000000005b60f4>] blk_mq_sched_dispatch_requests+0xa4/0x2a0
{SOFTIRQ-ON-W} state was registered at:
lock_acquire+0xec/0x2e0
_raw_spin_lock+0x44/0x70
blk_mq_sched_insert_request+0x88/0x1f0
blk_mq_requeue_work+0x108/0x180
process_one_work+0x310/0x800
worker_thread+0x88/0x520
kthread+0x164/0x1b0
ret_from_kernel_thread+0x5c/0x74
irq event stamp: 3572314
hardirqs last enabled at (3572314): [<c000000000b71998>] _raw_spin_unlock_irqrestore+0x58/0xb0
hardirqs last disabled at (3572313): [<c000000000b716ec>] _raw_spin_lock_irqsave+0x3c/0x90
softirqs last enabled at (3572302): [<c0000000000df17c>] irq_enter+0x9c/0xe0
softirqs last disabled at (3572303): [<c0000000000df2c8>] irq_exit+0x108/0x150
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(&(&hctx->lock)->rlock);
<Interrupt>
lock(&(&hctx->lock)->rlock);
*** DEADLOCK ***
2 locks held by swapper/28/0:
#0: ((&ipr_cmd->timer)){+.-...}, at: [<c0000000001936f0>] call_timer_fn+0x10/0x4b0
#1: (rcu_read_lock){......}, at: [<c0000000005aca60>] __blk_mq_run_hw_queue+0xa0/0x2c0
stack backtrace:
CPU: 28 PID: 0 Comm: swapper/28 Not tainted 4.13.0-rc2-gcc6x-gf74c89b #1
Call Trace:
[c000001fffe97550] [c000000000b50818] dump_stack+0xe8/0x160 (unreliable)
[c000001fffe97590] [c0000000001586d0] print_usage_bug+0x2d0/0x390
[c000001fffe97640] [c000000000158f34] mark_lock+0x7a4/0x8e0
[c000001fffe976f0] [c00000000015a000] __lock_acquire+0x6a0/0x1a70
[c000001fffe97860] [c00000000015befc] lock_acquire+0xec/0x2e0
[c000001fffe97930] [c000000000b71514] _raw_spin_lock+0x44/0x70
[c000001fffe97960] [c0000000005b60f4] blk_mq_sched_dispatch_requests+0xa4/0x2a0
[c000001fffe979c0] [c0000000005acac0] __blk_mq_run_hw_queue+0x100/0x2c0
[c000001fffe97a00] [c0000000005ad478] __blk_mq_delay_run_hw_queue+0x118/0x130
[c000001fffe97a40] [c0000000005ad61c] blk_mq_start_hw_queues+0x6c/0xa0
[c000001fffe97a80] [c000000000797aac] scsi_kick_queue+0x2c/0x60
[c000001fffe97aa0] [c000000000797cf0] scsi_run_queue+0x210/0x360
[c000001fffe97b10] [c00000000079b888] scsi_run_host_queues+0x48/0x80
[c000001fffe97b40] [c0000000007b6090] ipr_ioa_bringdown_done+0x70/0x1e0
[c000001fffe97bc0] [c0000000007bc860] ipr_reset_ioa_job+0x80/0xf0
[c000001fffe97bf0] [c0000000007b4d50] ipr_reset_timer_done+0xd0/0x100
[c000001fffe97c30] [c0000000001937bc] call_timer_fn+0xdc/0x4b0
[c000001fffe97cf0] [c000000000193d08] expire_timers+0x178/0x330
[c000001fffe97d60] [c0000000001940c8] run_timer_softirq+0xb8/0x120
[c000001fffe97de0] [c000000000b726a8] __do_softirq+0x168/0x6d8
[c000001fffe97ef0] [c0000000000df2c8] irq_exit+0x108/0x150
[c000001fffe97f10] [c000000000017bf4] __do_irq+0x2a4/0x4a0
[c000001fffe97f90] [c00000000002da50] call_do_irq+0x14/0x24
[c0000007fad93aa0] [c000000000017e8c] do_IRQ+0x9c/0x140
[c0000007fad93af0] [c000000000008b98] hardware_interrupt_common+0x138/0x140
--- interrupt: 501 at .L1.42+0x0/0x4
LR = arch_local_irq_restore.part.4+0x84/0xb0
Hello Jens,
scsi_run_queue() works fine if no scheduler is configured. Additionally, th=
at
code predates the introduction of blk-mq I/O schedulers. I think it is
nontrivial for block driver authors to figure out that a queue has to be ru=
n
from process context if a scheduler has been configured that does not suppo=
rt
to be run from interrupt context. How about adding WARN_ON_ONCE(in_interrup=
t())
to blk_mq_start_hw_queue() or replacing the above patch by the following:
Subject: [PATCH] blk-mq: Make it safe to call blk_mq_start_hw_queues() from=
interrupt context
blk_mq_start_hw_queues() triggers a queue run. Some functions that
get called to run a queue, e.g. dd_dispatch_request(), are not IRQ-safe.
Hence run the queue asynchronously if blk_mq_start_hw_queues() is called
from interrupt context.
Signed-off-by: Bart Van Assche <redacted>
---
block/blk-mq.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
Hello Jens,
scsi_run_queue() works fine if no scheduler is configured. Additionally, that
code predates the introduction of blk-mq I/O schedulers. I think it is
nontrivial for block driver authors to figure out that a queue has to be run
from process context if a scheduler has been configured that does not support
to be run from interrupt context.
No it doesn't, you could never run the queue from interrupt context with
async == false. So I don't think that's confusing at all, you should
always be aware of the context.
How about adding WARN_ON_ONCE(in_interrupt()) to
blk_mq_start_hw_queue() or replacing the above patch by the following:
No, I hate having dependencies like that, because they always just catch
one of them. Looks like the IPR path that hits this should just offload
to a workqueue or similar, you don't have to make any scsi_run_queue()
async.
--
Jens Axboe
From: Michael Ellerman <mpe@ellerman.id.au> Date: 2017-07-28 06:19:40
Jens Axboe [off-list ref] writes:
On 07/27/2017 08:47 AM, Bart Van Assche wrote:
quoted
On Thu, 2017-07-27 at 08:02 -0600, Jens Axboe wrote:
quoted
The bug looks like SCSI running the queue inline from IRQ
context, that's not a good idea.
...
quoted
scsi_run_queue() works fine if no scheduler is configured. Additionally, that
code predates the introduction of blk-mq I/O schedulers. I think it is
nontrivial for block driver authors to figure out that a queue has to be run
from process context if a scheduler has been configured that does not support
to be run from interrupt context.
No it doesn't, you could never run the queue from interrupt context with
async == false. So I don't think that's confusing at all, you should
always be aware of the context.
quoted
How about adding WARN_ON_ONCE(in_interrupt()) to
blk_mq_start_hw_queue() or replacing the above patch by the following:
No, I hate having dependencies like that, because they always just catch
one of them. Looks like the IPR path that hits this should just offload
to a workqueue or similar, you don't have to make any scsi_run_queue()
async.
On Thu, 2017-07-27 at 08:02 -0600, Jens Axboe wrote:
quoted
The bug looks like SCSI running the queue inline from IRQ
context, that's not a good idea.
...
quoted
quoted
scsi_run_queue() works fine if no scheduler is configured. Additionally, that
code predates the introduction of blk-mq I/O schedulers. I think it is
nontrivial for block driver authors to figure out that a queue has to be run
from process context if a scheduler has been configured that does not support
to be run from interrupt context.
No it doesn't, you could never run the queue from interrupt context with
async == false. So I don't think that's confusing at all, you should
always be aware of the context.
quoted
How about adding WARN_ON_ONCE(in_interrupt()) to
blk_mq_start_hw_queue() or replacing the above patch by the following:
No, I hate having dependencies like that, because they always just catch
one of them. Looks like the IPR path that hits this should just offload
to a workqueue or similar, you don't have to make any scsi_run_queue()
async.
OK, so the resolution is "fix it in IPR" ?
I'll leave that to the SCSI crew. But at least one bug is in IPR, if you
look at the call trace:
- timer function triggers, runs ipr_reset_timer_done(), which grabs the
host lock AND disables interrupts.
- further down in the call path, ipr_ioa_bringdown_done() uncondtionally
enables interrupts:
spin_unlock_irq(ioa_cfg->host->host_lock);
scsi_unblock_requests(ioa_cfg->host);
spin_lock_irq(ioa_cfg->host->host_lock);
And the call to scsi_unblock_requests() is the one that ultimately runs
the queue. The IRQ issue aside here, scsi_unblock_requests() could run
the queue async, and we could retain the normal sync run otherwise.
Can you try the below fix? Should be more palatable than the previous
one. Brian, maybe you can take a look at the IRQ issue mentioned above?
From: Bart Van Assche <hidden> Date: 2017-07-28 15:14:45
On Fri, 2017-07-28 at 08:25 -0600, Jens Axboe wrote:
On 07/28/2017 12:19 AM, Michael Ellerman wrote:
quoted
OK, so the resolution is "fix it in IPR" ?
=20
I'll leave that to the SCSI crew. But at least one bug is in IPR, if you
look at the call trace:
=20
- timer function triggers, runs ipr_reset_timer_done(), which grabs the
host lock AND disables interrupts.
- further down in the call path, ipr_ioa_bringdown_done() uncondtionally
enables interrupts:
=20
spin_unlock_irq(ioa_cfg->host->host_lock);
scsi_unblock_requests(ioa_cfg->host);
spin_lock_irq(ioa_cfg->host->host_lock);=20
=20
And the call to scsi_unblock_requests() is the one that ultimately runs
the queue. The IRQ issue aside here, scsi_unblock_requests() could run
the queue async, and we could retain the normal sync run otherwise.
=20
Can you try the below fix? Should be more palatable than the previous
one. Brian, maybe you can take a look at the IRQ issue mentioned above?
=20
[ ... ]
Hello Jens,
Are there other block drivers that can call blk_mq_start_hw_queues() from
interrupt context? I'm currently working on converting the skd driver
(drivers/block/skd_main.c) from a single queue block driver into a scsi-mq
driver. The skd driver calls blk_start_queue() from interrupt context. As w=
e
know it is not safe to call blk_mq_start_hw_queues() from interrupt context=
.
Can you recommend me how I should proceed: should I implement a solution in
the skd driver or should perhaps the blk-mq core be modified?
Thanks,
Bart.=
On Fri, 2017-07-28 at 08:25 -0600, Jens Axboe wrote:
quoted
On 07/28/2017 12:19 AM, Michael Ellerman wrote:
quoted
OK, so the resolution is "fix it in IPR" ?
I'll leave that to the SCSI crew. But at least one bug is in IPR, if you
look at the call trace:
- timer function triggers, runs ipr_reset_timer_done(), which grabs the
host lock AND disables interrupts.
- further down in the call path, ipr_ioa_bringdown_done() uncondtionally
enables interrupts:
spin_unlock_irq(ioa_cfg->host->host_lock);
scsi_unblock_requests(ioa_cfg->host);
spin_lock_irq(ioa_cfg->host->host_lock);
And the call to scsi_unblock_requests() is the one that ultimately runs
the queue. The IRQ issue aside here, scsi_unblock_requests() could run
the queue async, and we could retain the normal sync run otherwise.
Can you try the below fix? Should be more palatable than the previous
one. Brian, maybe you can take a look at the IRQ issue mentioned above?
[ ... ]
Hello Jens,
Are there other block drivers that can call blk_mq_start_hw_queues()
from interrupt context? I'm currently working on converting the skd
driver (drivers/block/skd_main.c) from a single queue block driver
into a scsi-mq driver. The skd driver calls blk_start_queue() from
interrupt context. As we know it is not safe to call
blk_mq_start_hw_queues() from interrupt context. Can you recommend me
how I should proceed: should I implement a solution in the skd driver
or should perhaps the blk-mq core be modified?
Great that you a converting that driver! If there's a need for it, we
could always expose the sync/async need in blk_mq_start_hw_queues().
From a quick look at the driver, it's using start queue very liberally.
Would probably make sense to see which ones of those are actually
needed. For resource management, we've got better interfaces on the
blk-mq side, for instance.
Since this is a conversion, might make sense to not modify
blk_mq_start_hw_queues() and simply provide an alternative
blk_mq_start_hw_queues_async(). That will keep the conversion straight
forward. Then the next step could be to fixup skd, and then we could
drop the _async() variant again, hopefully.
--
Jens Axboe
From: Brian King <hidden> Date: 2017-07-28 20:42:03
On 07/28/2017 10:17 AM, Brian J King wrote:
Jens Axboe [off-list ref] wrote on 07/28/2017 09:25:48 AM:
quoted
Can you try the below fix? Should be more palatable than the previous
one. Brian, maybe you can take a look at the IRQ issue mentioned above?
Michael,
Does this address the issue you are seeing?
Thanks,
Brian
8<
Index: linux-2.6.git/drivers/scsi/ipr.c
===================================================================
From: Michael Ellerman <mpe@ellerman.id.au> Date: 2017-07-31 12:03:37
Brian King [off-list ref] writes:
On 07/28/2017 10:17 AM, Brian J King wrote:
quoted
Jens Axboe [off-list ref] wrote on 07/28/2017 09:25:48 AM:
quoted
Can you try the below fix? Should be more palatable than the previous
one. Brian, maybe you can take a look at the IRQ issue mentioned above?
Michael,
Does this address the issue you are seeing?
Yes it seems to, thanks.
I only see the trace on reboot, and not 100% of the time. But I've
survived a couple of reboots now without seeing anything, so I think
this is helping.
I'll put the patch in my Jenkins over night and let you know how it
survives that, which should be ~= 25 boots.
cheers
From: Michael Ellerman <mpe@ellerman.id.au> Date: 2017-08-01 06:54:20
Michael Ellerman [off-list ref] writes:
Brian King [off-list ref] writes:
quoted
On 07/28/2017 10:17 AM, Brian J King wrote:
quoted
Jens Axboe [off-list ref] wrote on 07/28/2017 09:25:48 AM:
quoted
Can you try the below fix? Should be more palatable than the previous
one. Brian, maybe you can take a look at the IRQ issue mentioned above?
Michael,
Does this address the issue you are seeing?
Yes it seems to, thanks.
I only see the trace on reboot, and not 100% of the time. But I've
survived a couple of reboots now without seeing anything, so I think
this is helping.
I'll put the patch in my Jenkins over night and let you know how it
survives that, which should be ~= 25 boots.
No lockdep warnings or other oddness over night, so that patch looks
good to me.
cheers
Can you try the below fix? Should be more palatable than the previous
one. Brian, maybe you can take a look at the IRQ issue mentioned above?
Given the patch from Brian fixed the lockdep warning, do you still want
me to try and test this one?
Nope, we don't have to do that. I'd much rather just add a WARN_ON()
or similar to make sure we catch buggy users earlier. scsi_run_queue()
needs a
WARN_ON(in_interrupt());
but it might be better to put that in __blk_mq_run_hw_queue().
--
Jens Axboe