* nvmet: Kernel v4.19-rc4 circular locking complaint
@ 2018-09-20 17:49 Bart Van Assche
2018-09-25 23:27 ` Christoph Hellwig
2018-09-26 5:38 ` Sagi Grimberg
0 siblings, 2 replies; 4+ messages in thread
From: Bart Van Assche @ 2018-09-20 17:49 UTC (permalink / raw)
Hello,
Here is another complaint that appeared while running the nvmeof-mp tests.
Sagi, I have Cc-ed you because I think that this complaint may be related
to the flush_scheduled_work() call that was inserted in
nvmet_rdma_queue_connect() by commit 777dc82395de ("nvmet-rdma: occasionally
flush ongoing controller teardown"). It seems weird to me that work is
flushed from the context of an RDMA/CM handler, which is running in the
context of a work item itself.
Bart.
======================================================
WARNING: possible circular locking dependency detected
4.19.0-rc4-dbg+ #3 Not tainted
------------------------------------------------------
kworker/5:0/39 is trying to acquire lock:
00000000a10b6db9 (&id_priv->handler_mutex){+.+.}, at: rdma_destroy_id+0x6f/0x440 [rdma_cm]
but task is already holding lock:
00000000331b4e2c ((work_completion)(&queue->release_work)){+.+.}, at: process_one_work+0x3ed/0xa20
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #3 ((work_completion)(&queue->release_work)){+.+.}:
process_one_work+0x474/0xa20
worker_thread+0x63/0x5a0
kthread+0x1cf/0x1f0
ret_from_fork+0x24/0x30
-> #2 ((wq_completion)"events"){+.+.}:
flush_workqueue+0xf3/0x970
nvmet_rdma_cm_handler+0x133d/0x1734 [nvmet_rdma]
cma_ib_req_handler+0x72f/0xf90 [rdma_cm]
cm_process_work+0x2e/0x110 [ib_cm]
cm_req_handler+0x135b/0x1c30 [ib_cm]
cm_work_handler+0x2b7/0x38cd [ib_cm]
process_one_work+0x4ae/0xa20
nvmet_rdma:nvmet_rdma_cm_handler: nvmet_rdma: disconnected (10): status 0 id 0000000040357082
worker_thread+0x63/0x5a0
kthread+0x1cf/0x1f0
ret_from_fork+0x24/0x30
nvme nvme0: Reconnecting in 10 seconds...
-> #1 (&id_priv->handler_mutex/1){+.+.}:
__mutex_lock+0xfe/0xbe0
mutex_lock_nested+0x1b/0x20
cma_ib_req_handler+0x6aa/0xf90 [rdma_cm]
cm_process_work+0x2e/0x110 [ib_cm]
cm_req_handler+0x135b/0x1c30 [ib_cm]
cm_work_handler+0x2b7/0x38cd [ib_cm]
process_one_work+0x4ae/0xa20
worker_thread+0x63/0x5a0
kthread+0x1cf/0x1f0
ret_from_fork+0x24/0x30
-> #0 (&id_priv->handler_mutex){+.+.}:
lock_acquire+0xc5/0x200
__mutex_lock+0xfe/0xbe0
mutex_lock_nested+0x1b/0x20
rdma_destroy_id+0x6f/0x440 [rdma_cm]
nvmet_rdma_release_queue_work+0x8e/0x1b0 [nvmet_rdma]
process_one_work+0x4ae/0xa20
worker_thread+0x63/0x5a0
kthread+0x1cf/0x1f0
ret_from_fork+0x24/0x30
other info that might help us debug this:
Chain exists of:
&id_priv->handler_mutex --> (wq_completion)"events" --> (work_completion)(&queue->release_work)
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock((work_completion)(&queue->release_work));
lock((wq_completion)"events");
lock((work_completion)(&queue->release_work));
lock(&id_priv->handler_mutex);
*** DEADLOCK ***
2 locks held by kworker/5:0/39:
#0: 0000000071b4905b ((wq_completion)"events"){+.+.}, at: process_one_work+0x3ed/0xa20
#1: 00000000331b4e2c ((work_completion)(&queue->release_work)){+.+.}, at: process_one_work+0x3ed/0xa20
stack backtrace:
CPU: 5 PID: 39 Comm: kworker/5:0 Not tainted 4.19.0-rc4-dbg+ #3
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
Workqueue: events nvmet_rdma_release_queue_work [nvmet_rdma]
Call Trace:
dump_stack+0x86/0xc5
print_circular_bug.isra.32+0x20a/0x218
__lock_acquire+0x1a54/0x1b20
print_req_error: I/O error, dev dm-0, sector 65528
print_req_error: I/O error, dev dm-0, sector 65528
Buffer I/O error on dev dm-0, logical block 8191, async page read
print_req_error: I/O error, dev dm-0, sector 0
lock_acquire+0xc5/0x200
Buffer I/O error on dev dm-0, logical block 0, async page read
__mutex_lock+0xfe/0xbe0
print_req_error: I/O error, dev dm-0, sector 0
Buffer I/O error on dev dm-0, logical block 0, async page read
Buffer I/O error on dev dm-0, logical block 3, async page read
mutex_lock_nested+0x1b/0x20
rdma_destroy_id+0x6f/0x440 [rdma_cm]
nvmet_rdma_release_queue_work+0x8e/0x1b0 [nvmet_rdma]
process_one_work+0x4ae/0xa20
worker_thread+0x63/0x5a0
kthread+0x1cf/0x1f0
ret_from_fork+0x24/0x30
^ permalink raw reply [flat|nested] 4+ messages in thread
* nvmet: Kernel v4.19-rc4 circular locking complaint
2018-09-20 17:49 nvmet: Kernel v4.19-rc4 circular locking complaint Bart Van Assche
@ 2018-09-25 23:27 ` Christoph Hellwig
2018-09-26 5:38 ` Sagi Grimberg
1 sibling, 0 replies; 4+ messages in thread
From: Christoph Hellwig @ 2018-09-25 23:27 UTC (permalink / raw)
On Thu, Sep 20, 2018@10:49:40AM -0700, Bart Van Assche wrote:
> Hello,
>
> Here is another complaint that appeared while running the nvmeof-mp tests.
> Sagi, I have Cc-ed you because I think that this complaint may be related
> to the flush_scheduled_work() call that was inserted in
> nvmet_rdma_queue_connect() by commit 777dc82395de ("nvmet-rdma: occasionally
> flush ongoing controller teardown"). It seems weird to me that work is
> flushed from the context of an RDMA/CM handler, which is running in the
> context of a work item itself.
Yes, this seems pretty dangerous. For now I'm tempted to revert the
commit. Sagi?
^ permalink raw reply [flat|nested] 4+ messages in thread
* nvmet: Kernel v4.19-rc4 circular locking complaint
2018-09-20 17:49 nvmet: Kernel v4.19-rc4 circular locking complaint Bart Van Assche
2018-09-25 23:27 ` Christoph Hellwig
@ 2018-09-26 5:38 ` Sagi Grimberg
2018-09-27 15:42 ` Bart Van Assche
1 sibling, 1 reply; 4+ messages in thread
From: Sagi Grimberg @ 2018-09-26 5:38 UTC (permalink / raw)
> Hello,
Thanks for reporting Bart!
> Here is another complaint that appeared while running the nvmeof-mp tests.
> Sagi, I have Cc-ed you because I think that this complaint may be related
> to the flush_scheduled_work() call that was inserted in
> nvmet_rdma_queue_connect() by commit 777dc82395de ("nvmet-rdma: occasionally
> flush ongoing controller teardown"). It seems weird to me that work is
> flushed from the context of an RDMA/CM handler, which is running in the
> context of a work item itself.
Your right, the point was to make sure we free resources (async) in
rapid connect/disconnect scenarios.
I think that moving release work to a private wq should help, does it
make this complaint go away?
--
diff --git a/drivers/nvme/target/rdma.c b/drivers/nvme/target/rdma.c
index bfc4da660bb4..5becca88ccbe 100644
--- a/drivers/nvme/target/rdma.c
+++ b/drivers/nvme/target/rdma.c
@@ -122,6 +122,7 @@ struct nvmet_rdma_device {
int inline_page_count;
};
+struct workqueue_struct *nvmet_rdma_delete_wq;
static bool nvmet_rdma_use_srq;
module_param_named(use_srq, nvmet_rdma_use_srq, bool, 0444);
MODULE_PARM_DESC(use_srq, "Use shared receive queue.");
@@ -1267,12 +1268,12 @@ static int nvmet_rdma_queue_connect(struct
rdma_cm_id *cm_id,
if (queue->host_qid == 0) {
/* Let inflight controller teardown complete */
- flush_scheduled_work();
+ flush_workqueue(nvmet_rdma_delete_wq);
}
ret = nvmet_rdma_cm_accept(cm_id, queue, &event->param.conn);
if (ret) {
- schedule_work(&queue->release_work);
+ queue_work(nvmet_rdma_delete_wq, &queue->release_work);
/* Destroying rdma_cm id is not needed here */
return 0;
}
@@ -1337,7 +1338,7 @@ static void __nvmet_rdma_queue_disconnect(struct
nvmet_rdma_queue *queue)
if (disconnect) {
rdma_disconnect(queue->cm_id);
- schedule_work(&queue->release_work);
+ queue_work(nvmet_rdma_delete_wq, &queue->release_work);
}
}
@@ -1367,7 +1368,7 @@ static void nvmet_rdma_queue_connect_fail(struct
rdma_cm_id *cm_id,
mutex_unlock(&nvmet_rdma_queue_mutex);
pr_err("failed to connect queue %d\n", queue->idx);
- schedule_work(&queue->release_work);
+ queue_work(nvmet_rdma_delete_wq, &queue->release_work);
}
/**
@@ -1649,8 +1650,17 @@ static int __init nvmet_rdma_init(void)
if (ret)
goto err_ib_client;
+ nvmet_rdma_delete_wq = alloc_workqueue("nvmet-rdma-delete-wq",
+ WQ_UNBOUND | WQ_MEM_RECLAIM | WQ_SYSFS, 0);
+ if (!nvmet_rdma_delete_wq) {
+ ret = -ENOMEM;
+ goto err_unreg_transport;
+ }
+
return 0;
+err_unreg_transport:
+ nvmet_unregister_transport(&nvmet_rdma_ops);
err_ib_client:
ib_unregister_client(&nvmet_rdma_ib_client);
return ret;
@@ -1658,6 +1668,7 @@ static int __init nvmet_rdma_init(void)
static void __exit nvmet_rdma_exit(void)
{
+ destroy_workqueue(nvmet_rdma_delete_wq);
nvmet_unregister_transport(&nvmet_rdma_ops);
ib_unregister_client(&nvmet_rdma_ib_client);
WARN_ON_ONCE(!list_empty(&nvmet_rdma_queue_list));
--
^ permalink raw reply related [flat|nested] 4+ messages in thread
* nvmet: Kernel v4.19-rc4 circular locking complaint
2018-09-26 5:38 ` Sagi Grimberg
@ 2018-09-27 15:42 ` Bart Van Assche
0 siblings, 0 replies; 4+ messages in thread
From: Bart Van Assche @ 2018-09-27 15:42 UTC (permalink / raw)
On Tue, 2018-09-25@22:38 -0700, Sagi Grimberg wrote:
> I think that moving release work to a private wq should help, does it
> make this complaint go away?
Hi Sagi,
Thanks for the patch. However, it seems like your patch got line-wrapped.
Can you resend it?
Thanks,
Bart.
$ patch -p1 < ~/Re\:_nvmet\:_Kernel_v4.19-rc4_circular_locking_complaint.mbox
(Stripping trailing CRs from patch; use --binary to disable.)
patching file drivers/nvme/target/rdma.c
Hunk #1 FAILED at 122.
patch: **** malformed patch at line 129: rdma_cm_id *cm_id,
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2018-09-27 15:42 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-09-20 17:49 nvmet: Kernel v4.19-rc4 circular locking complaint Bart Van Assche
2018-09-25 23:27 ` Christoph Hellwig
2018-09-26 5:38 ` Sagi Grimberg
2018-09-27 15:42 ` Bart Van Assche
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.