Hello
On my NVMe RDMA qedr iWARP environment, reset_controller will lead bellow BUG, could anyone help check this issue.
Steps:
nvme connect -t rdma -a 172.31.50.102 -s 4420 -n testnqn
sleep 1
echo 1 >/sys/block/nvme0c0n1/device/reset_controller
HW:
# lspci | grep -i ql
08:00.0 Ethernet controller: QLogic Corp. FastLinQ QL45000 Series 25GbE Controller (rev 10)
08:00.1 Ethernet controller: QLogic Corp. FastLinQ QL45000 Series 25GbE Controller (rev 10)
dmesg:
client:
[ 153.609662] iwpm_register_pid: Unable to send a nlmsg (client = 2)
[ 153.679142] nvme nvme0: creating 12 I/O queues.
[ 154.447885] nvme nvme0: mapped 12/0/0 default/read/poll queues.
[ 154.527204] nvme nvme0: new ctrl: NQN "testnqn", addr 172.31.50.102:4420
[ 154.554852] nvme0n1: detected capacity change from 0 to 268435456000
[ 173.337907] ==================================================================
[ 173.346307] BUG: KASAN: use-after-free in qed_chain_free+0x6d2/0x7f0 [qed]
[ 173.354065] Read of size 8 at addr ffff888242305000 by task kworker/u96:5/574
[ 173.363795] CPU: 3 PID: 574 Comm: kworker/u96:5 Not tainted 5.6.0-rc4 #1
[ 173.371350] Hardware name: Dell Inc. PowerEdge R320/0KM5PX, BIOS 2.7.0 08/19/2019
[ 173.379787] Workqueue: nvme-reset-wq nvme_rdma_reset_ctrl_work [nvme_rdma]
[ 173.387537] Call Trace:
[ 173.390305] dump_stack+0x96/0xe0
[ 173.394062] ? qed_chain_free+0x6d2/0x7f0 [qed]
[ 173.399175] print_address_description.constprop.6+0x1b/0x220
[ 173.405667] ? qed_chain_free+0x6d2/0x7f0 [qed]
[ 173.410790] ? qed_chain_free+0x6d2/0x7f0 [qed]
[ 173.415915] __kasan_report.cold.9+0x37/0x77
[ 173.420737] ? quarantine_put+0x10/0x160
[ 173.425174] ? qed_chain_free+0x6d2/0x7f0 [qed]
[ 173.430290] kasan_report+0xe/0x20
[ 173.434141] qed_chain_free+0x6d2/0x7f0 [qed]
[ 173.439067] ? __kasan_slab_free+0x13a/0x170
[ 173.443915] ? qed_hw_remove+0x2b0/0x2b0 [qed]
[ 173.448947] qedr_cleanup_kernel+0xbf/0x420 [qedr]
[ 173.454367] ? qed_rdma_modify_srq+0x3c0/0x3c0 [qed]
[ 173.459991] ? qed_rdma_modify_srq+0x3c0/0x3c0 [qed]
[ 173.465595] qedr_destroy_qp+0x2b0/0x670 [qedr]
[ 173.470703] ? qedr_query_qp+0x1300/0x1300 [qedr]
[ 173.476015] ? _raw_spin_unlock_irq+0x24/0x30
[ 173.480944] ? wait_for_completion+0xc2/0x3d0
[ 173.485861] ? wait_for_completion_interruptible+0x440/0x440
[ 173.492258] ? mark_held_locks+0x78/0x130
[ 173.496784] ? _raw_spin_unlock_irqrestore+0x3e/0x50
[ 173.502385] ? lockdep_hardirqs_on+0x388/0x570
[ 173.507432] ib_destroy_qp_user+0x2ba/0x6c0 [ib_core]
[ 173.513148] nvme_rdma_destroy_queue_ib+0xc8/0x1a0 [nvme_rdma]
[ 173.519732] nvme_rdma_free_queue+0x2a/0x60 [nvme_rdma]
[ 173.525626] nvme_rdma_destroy_io_queues+0xb1/0x170 [nvme_rdma]
[ 173.532321] nvme_rdma_shutdown_ctrl+0x62/0xd0 [nvme_rdma]
[ 173.538510] nvme_rdma_reset_ctrl_work+0x2c/0xa0 [nvme_rdma]
[ 173.544908] process_one_work+0x920/0x1740
[ 173.549546] ? pwq_dec_nr_in_flight+0x2d0/0x2d0
[ 173.556213] worker_thread+0x87/0xb40
[ 173.561852] ? process_one_work+0x1740/0x1740
[ 173.568315] kthread+0x333/0x400
[ 173.573492] ? kthread_create_on_node+0xc0/0xc0
[ 173.580094] ret_from_fork+0x3a/0x50
[ 173.588720] The buggy address belongs to the page:
[ 173.595559] page:ffffea000908c140 refcount:0 mapcount:0 mapping:0000000000000000 index:0x0
[ 173.606353] flags: 0x17ffffc0000000()
[ 173.611933] raw: 0017ffffc0000000 0000000000000000 ffffea000908c108 0000000000000000
[ 173.622111] raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
[ 173.632309] page dumped because: kasan: bad access detected
[ 173.643129] Memory state around the buggy address:
[ 173.649935] ffff888242304f00: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
[ 173.659491] ffff888242304f80: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
[ 173.669005] >ffff888242305000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
[ 173.678511] ^
[ 173.683535] ffff888242305080: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
[ 173.693079] ffff888242305100: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
[ 173.702578] ==================================================================
[ 173.712132] Disabling lock debugging due to kernel taint
[ 174.480153] nvme nvme0: creating 12 I/O queues.
target:
[ 105.823713] null_blk: module loaded
[ 106.188952] nvmet: adding nsid 1 to subsystem testnqn
[ 106.209393] iwpm_register_pid: Unable to send a nlmsg (client = 2)
[ 106.217135] nvmet_rdma: enabling port 2 (172.31.50.102:4420)
[ 148.399402] nvmet: creating controller 1 for subsystem testnqn for NQN nqn.2014-08.org.nvmexpress:uuid:5cf10916-b4ca-45cd-956c-ab680ec3e636.
[ 167.842446]
[ 167.844133] ======================================================
[ 167.851087] WARNING: possible circular locking dependency detected
[ 167.858037] 5.6.0-rc4 #2 Not tainted
[ 167.862070] ------------------------------------------------------
[ 167.869018] kworker/2:1/141 is trying to acquire lock:
[ 167.874794] ffff8882581573e0 (&id_priv->handler_mutex){+.+.}, at: rdma_destroy_id+0x108/0xc70 [rdma_cm]
[ 167.885361]
[ 167.885361] but task is already holding lock:
[ 167.891918] ffffc9000403fe00 ((work_completion)(&queue->release_work)){+.+.}, at: process_one_work+0x82d/0x1740
[ 167.903261]
[ 167.903261] which lock already depends on the new lock.
[ 167.903261]
[ 167.912449]
[ 167.912449] the existing dependency chain (in reverse order) is:
[ 167.920861]
[ 167.920861] -> #3 ((work_completion)(&queue->release_work)){+.+.}:
[ 167.929468] process_one_work+0x87f/0x1740
[ 167.934656] worker_thread+0x87/0xb40
[ 167.939356] kthread+0x333/0x400
[ 167.943569] ret_from_fork+0x3a/0x50
[ 167.948172]
[ 167.948172] -> #2 ((wq_completion)events){+.+.}:
[ 167.955038] flush_workqueue+0xf7/0x13c0
[ 167.960028] nvmet_rdma_queue_connect+0x15e0/0x1d60 [nvmet_rdma]
[ 167.967368] cma_cm_event_handler+0xb7/0x550 [rdma_cm]
[ 167.973743] iw_conn_req_handler+0x93c/0xdb0 [rdma_cm]
[ 167.980104] cm_work_handler+0x12d2/0x1920 [iw_cm]
[ 167.986093] process_one_work+0x920/0x1740
[ 167.991280] worker_thread+0x87/0xb40
[ 167.995984] kthread+0x333/0x400
[ 168.000199] ret_from_fork+0x3a/0x50
[ 168.004804]
[ 168.004804] -> #1 (&id_priv->handler_mutex/1){+.+.}:
[ 168.012051] __mutex_lock+0x13e/0x1420
[ 168.016857] iw_conn_req_handler+0x369/0xdb0 [rdma_cm]
[ 168.023217] cm_work_handler+0x12d2/0x1920 [iw_cm]
[ 168.030777] process_one_work+0x920/0x1740
[ 168.037564] worker_thread+0x87/0xb40
[ 168.043852] kthread+0x333/0x400
[ 168.049681] ret_from_fork+0x3a/0x50
[ 168.055836]
[ 168.055836] -> #0 (&id_priv->handler_mutex){+.+.}:
[ 168.065925] __lock_acquire+0x2313/0x3d90
[ 168.072505] lock_acquire+0x15a/0x3c0
[ 168.078664] __mutex_lock+0x13e/0x1420
[ 168.084907] rdma_destroy_id+0x108/0xc70 [rdma_cm]
[ 168.092257] nvmet_rdma_release_queue_work+0xcc/0x390 [nvmet_rdma]
[ 168.101213] process_one_work+0x920/0x1740
[ 168.107798] worker_thread+0x87/0xb40
[ 168.113875] kthread+0x333/0x400
[ 168.119461] ret_from_fork+0x3a/0x50
[ 168.125397]
[ 168.125397] other info that might help us debug this:
[ 168.125397]
[ 168.138272] Chain exists of:
[ 168.138272] &id_priv->handler_mutex --> (wq_completion)events --> (work_completion)(&queue->release_work)
[ 168.138272]
[ 168.157850] Possible unsafe locking scenario:
[ 168.157850]
[ 168.166962] CPU0 CPU1
[ 168.173311] ---- ----
[ 168.179615] lock((work_completion)(&queue->release_work));
[ 168.187210] lock((wq_completion)events);
[ 168.195872] lock((work_completion)(&queue->release_work));
[ 168.206278] lock(&id_priv->handler_mutex);
[ 168.212326]
[ 168.212326] *** DEADLOCK ***
[ 168.212326]
[ 168.222662] 2 locks held by kworker/2:1/141:
[ 168.228688] #0: ffff888107c23148 ((wq_completion)events){+.+.}, at: process_one_work+0x7f9/0x1740
[ 168.240058] #1: ffffc9000403fe00 ((work_completion)(&queue->release_work)){+.+.}, at: process_one_work+0x82d/0x1740
[ 168.253205]
[ 168.253205] stack backtrace:
[ 168.260685] CPU: 2 PID: 141 Comm: kworker/2:1 Not tainted 5.6.0-rc4 #2
[ 168.269346] Hardware name: Dell Inc. PowerEdge R320/0KM5PX, BIOS 2.7.0 08/19/2019
[ 168.279143] Workqueue: events nvmet_rdma_release_queue_work [nvmet_rdma]
[ 168.288059] Call Trace:
[ 168.292229] dump_stack+0x96/0xe0
[ 168.297373] check_noncircular+0x356/0x410
[ 168.303372] ? ftrace_caller_op_ptr+0xe/0xe
[ 168.309444] ? print_circular_bug.isra.40+0x1e0/0x1e0
[ 168.316482] ? unwind_next_frame+0x1c5/0x1bb0
[ 168.322765] ? ret_from_fork+0x3a/0x50
[ 168.328372] ? perf_trace_lock_acquire+0x630/0x630
[ 168.335165] ? mark_lock+0xbe/0x1130
[ 168.340545] ? nvmet_rdma_release_queue_work+0xcc/0x390 [nvmet_rdma]
[ 168.349120] __lock_acquire+0x2313/0x3d90
[ 168.355086] ? ret_from_fork+0x3a/0x50
[ 168.360701] ? lockdep_hardirqs_on+0x570/0x570
[ 168.367151] ? stack_trace_save+0x8a/0xb0
[ 168.373093] ? stack_trace_consume_entry+0x160/0x160
[ 168.380122] lock_acquire+0x15a/0x3c0
[ 168.385648] ? rdma_destroy_id+0x108/0xc70 [rdma_cm]
[ 168.392633] __mutex_lock+0x13e/0x1420
[ 168.398287] ? rdma_destroy_id+0x108/0xc70 [rdma_cm]
[ 168.405298] ? sched_clock+0x5/0x10
[ 168.410614] ? rdma_destroy_id+0x108/0xc70 [rdma_cm]
[ 168.417582] ? find_held_lock+0x3a/0x1c0
[ 168.423452] ? mutex_lock_io_nested+0x12a0/0x12a0
[ 168.430200] ? mark_lock+0xbe/0x1130
[ 168.435644] ? mark_held_locks+0x78/0x130
[ 168.441569] ? _raw_spin_unlock_irqrestore+0x3e/0x50
[ 168.448574] ? rdma_destroy_id+0x108/0xc70 [rdma_cm]
[ 168.455564] rdma_destroy_id+0x108/0xc70 [rdma_cm]
[ 168.462344] nvmet_rdma_release_queue_work+0xcc/0x390 [nvmet_rdma]
[ 168.470665] process_one_work+0x920/0x1740
[ 168.476651] ? pwq_dec_nr_in_flight+0x2d0/0x2d0
[ 168.483200] worker_thread+0x87/0xb40
[ 168.488751] ? __kthread_parkme+0xc3/0x190
[ 168.494769] ? process_one_work+0x1740/0x1740
[ 168.501104] kthread+0x333/0x400
[ 168.506157] ? kthread_create_on_node+0xc0/0xc0
[ 168.512619] ret_from_fork+0x3a/0x50
[ 168.523833] ==================================================================
[ 168.533446] BUG: KASAN: use-after-free in qed_chain_free+0x6d2/0x7f0 [qed]
[ 168.542658] Read of size 8 at addr ffff88823b8dd000 by task kworker/2:1/141
[ 168.551970]
[ 168.555135] CPU: 2 PID: 141 Comm: kworker/2:1 Not tainted 5.6.0-rc4 #2
[ 168.563922] Hardware name: Dell Inc. PowerEdge R320/0KM5PX, BIOS 2.7.0 08/19/2019
[ 168.573747] Workqueue: events nvmet_rdma_release_queue_work [nvmet_rdma]
[ 168.582718] Call Trace:
[ 168.586936] dump_stack+0x96/0xe0
[ 168.592134] ? qed_chain_free+0x6d2/0x7f0 [qed]
[ 168.598635] print_address_description.constprop.6+0x1b/0x220
[ 168.606500] ? qed_chain_free+0x6d2/0x7f0 [qed]
[ 168.613049] ? qed_chain_free+0x6d2/0x7f0 [qed]
[ 168.619527] __kasan_report.cold.9+0x37/0x77
[ 168.625793] ? qed_chain_free+0x6d2/0x7f0 [qed]
[ 168.632309] kasan_report+0xe/0x20
[ 168.637576] qed_chain_free+0x6d2/0x7f0 [qed]
[ 168.643913] ? __kasan_slab_free+0x13a/0x170
[ 168.650140] ? qed_hw_remove+0x2b0/0x2b0 [qed]
[ 168.656527] qedr_cleanup_kernel+0xbf/0x420 [qedr]
[ 168.663339] ? qed_rdma_modify_srq+0x3c0/0x3c0 [qed]
[ 168.670321] ? qed_rdma_modify_srq+0x3c0/0x3c0 [qed]
[ 168.677273] qedr_destroy_qp+0x2b0/0x670 [qedr]
[ 168.683714] ? qedr_query_qp+0x1300/0x1300 [qedr]
[ 168.690368] ? _raw_spin_unlock_irq+0x24/0x30
[ 168.696614] ? wait_for_completion+0xc2/0x3d0
[ 168.702877] ? wait_for_completion_interruptible+0x440/0x440
[ 168.710616] ib_destroy_qp_user+0x2ba/0x6c0 [ib_core]
[ 168.717630] ? nvmet_rdma_release_queue_work+0xcc/0x390 [nvmet_rdma]
[ 168.726186] nvmet_rdma_release_queue_work+0xd6/0x390 [nvmet_rdma]
[ 168.734511] process_one_work+0x920/0x1740
[ 168.740492] ? pwq_dec_nr_in_flight+0x2d0/0x2d0
[ 168.746992] worker_thread+0x87/0xb40
[ 168.752524] ? __kthread_parkme+0xc3/0x190
[ 168.758547] ? process_one_work+0x1740/0x1740
[ 168.764890] kthread+0x333/0x400
[ 168.769952] ? kthread_create_on_node+0xc0/0xc0
[ 168.776445] ret_from_fork+0x3a/0x50
[ 168.781870]
[ 168.784929] Allocated by task 802:
[ 168.790166] save_stack+0x19/0x80
[ 168.795248] __kasan_kmalloc.constprop.11+0xc1/0xd0
[ 168.802127] kmem_cache_alloc+0xf9/0x370
[ 168.807931] getname_flags+0xba/0x510
[ 168.813388] user_path_at_empty+0x1d/0x40
[ 168.819250] do_faccessat+0x21f/0x610
[ 168.824700] do_syscall_64+0x9f/0x4f0
[ 168.830184] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 168.837191]
[ 168.840197] Freed by task 802:
[ 168.844919] save_stack+0x19/0x80
[ 168.849914] __kasan_slab_free+0x125/0x170
[ 168.855758] kmem_cache_free+0xcd/0x3c0
[ 168.861291] filename_lookup.part.63+0x1e7/0x330
[ 168.867662] do_faccessat+0x21f/0x610
[ 168.872961] do_syscall_64+0x9f/0x4f0
[ 168.878246] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 168.885124]
[ 168.887977] The buggy address belongs to the object at ffff88823b8dc400
[ 168.887977] which belongs to the cache names_cache of size 4096
[ 168.904533] The buggy address is located 3072 bytes inside of
[ 168.904533] 4096-byte region [ffff88823b8dc400, ffff88823b8dd400)
[ 168.920388] The buggy address belongs to the page:
[ 168.927046] page:ffffea0008ee3600 refcount:1 mapcount:0 mapping:ffff888107fe5280 index:0x0 compound_mapcount: 0
[ 168.939650] flags: 0x17ffffc0010200(slab|head)
[ 168.945986] raw: 0017ffffc0010200 dead000000000100 dead000000000122 ffff888107fe5280
[ 168.956074] raw: 0000000000000000 0000000000070007 00000001ffffffff 0000000000000000
[ 168.966185] page dumped because: kasan: bad access detected
[ 168.973835]
[ 168.976923] Memory state around the buggy address:
[ 168.983705] ffff88823b8dcf00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 168.993270] ffff88823b8dcf80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 169.002799] >ffff88823b8dd000: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 169.012337] ^
[ 169.017384] ffff88823b8dd080: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 169.026938] ffff88823b8dd100: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 169.036457] ==================================================================
[ 169.183961] nvmet: creating controller 1 for subsystem testnqn for NQN nqn.2014-08.org.nvmexpress:uuid:5cf10916-b4ca-45cd-956c-ab680ec3e636.
Best Regards,
Yi Zhang
_______________________________________________
linux-nvme mailing list
linux-nvme@xxxxxxxxxxxxxxxxxxx
http://lists.infradead.org/mailman/listinfo/linux-nvme
