linux-block/for-next nvme_trtype=tcp blktest nvme/005
Chaitanya Kulkarni
chaitanyak at nvidia.com
Tue Nov 11 10:28:04 PST 2025
Re-sending it last time due to messed-up formatting.
On 11/11/25 10:16, Chaitanya Kulkarni wrote:
> Hi,
>
> Please have a look, if there is already for this please ignore.
>
> Running blktests on latest linux-block/for-next resulting in this :-
> nvme/005 (tr=tcp) (reset local loopback target) [failed] runtime 0.264s
> ... 0.698s something found in dmesg: [ 1020.045983] run blktests
> nvme/005 at 2025-11-11 10:10:22 [ 1020.089904] loop3: detected capacity
> change from 0 to 1024000 [ 1020.121953] nvmet: adding nsid 1 to
> subsystem blktests-subsystem-1 [ 1020.133610] nvmet_tcp: enabling port 0
> (127.0.0.1:4420) [ 1020.169237] nvmet: Created nvm controller 1 for
> subsystem blktests-subsystem-1 for NQN
> nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349. [
> 1020.173913] nvme nvme0: creating 48 I/O queues. [ 1020.186875] nvme
> nvme0: mapped 48/0/0 default/read/poll queues. [ 1020.202188] nvme
> nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420,
> hostnqn:
> nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349 [
> 1020.283741] nvmet: Created nvm controller 2 for subsystem
[...]
Running blktests on latest linux-block/for-next resulting in this,
if there is a fix please ignore this :-
nvme/005 (tr=tcp) (reset local loopback target) [failed]
runtime 0.264s ... 0.698s
something found in dmesg:
[ 1020.045983] run blktests nvme/005 at 2025-11-11 10:10:22
[ 1020.089904] loop3: detected capacity change from 0 to 1024000
[ 1020.121953] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 1020.133610] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 1020.169237] nvmet: Created nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349.
[ 1020.173913] nvme nvme0: creating 48 I/O queues.
[ 1020.186875] nvme nvme0: mapped 48/0/0 default/read/poll queues.
[ 1020.202188] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420, hostnqn: nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349
[ 1020.283741] nvmet: Created nvm controller 2 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349.
...
(See '/root/blktests/results/nodev_tr_tcp/nvme/005.dmesg' for the entire message)
1020.045983] run blktests nvme/005 at 2025-11-11 10:10:22
[ 1020.089904] loop3: detected capacity change from 0 to 1024000
[ 1020.121953] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 1020.133610] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 1020.169237] nvmet: Created nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349.
[ 1020.173913] nvme nvme0: creating 48 I/O queues.
[ 1020.186875] nvme nvme0: mapped 48/0/0 default/read/poll queues.
[ 1020.202188] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420, hostnqn: nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349
[ 1020.283741] nvmet: Created nvm controller 2 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349.
[ 1020.284486] ======================================================
[ 1020.284489] WARNING: possible circular locking dependency detected
[ 1020.284491] 6.18.0-rc4lblk+ #4 Tainted: G N
[ 1020.284493] ------------------------------------------------------
[ 1020.284494] kworker/34:1/323 is trying to acquire lock:
[ 1020.284496] ffffffff82e487e0 (fs_reclaim){+.+.}-{0:0}, at: kmem_cache_alloc_node_noprof+0x5a/0x770
[ 1020.284507]
but task is already holding lock:
[ 1020.284508] ffff888167d88e98 (sk_lock-AF_INET-NVME
[ 1020.295133] nvme nvme0: creating 48 I/O queues.
[ 1020.298979] ){+.+.}-{0:0}, at: tcp_close+0x15/0x80
[ 1020.298988]
which lock already depends on the new lock.
[ 1020.298989]
the existing dependency chain (in reverse order) is:
[ 1020.298990]
-> #4 (sk_lock-AF_INET-NVME){+.+.}-{0:0}:
[ 1020.298994] lock_sock_nested+0x2e/0x70
[ 1020.352551] tcp_sendmsg+0x1a/0x40
[ 1020.354669] sock_sendmsg+0xed/0x110
[ 1020.356831] nvme_tcp_try_send_cmd_pdu+0x13e/0x260 [nvme_tcp]
[ 1020.360129] nvme_tcp_try_send+0xb3/0x330 [nvme_tcp]
[ 1020.363018] nvme_tcp_queue_rq+0x342/0x3d0 [nvme_tcp]
[ 1020.365975] blk_mq_dispatch_rq_list+0x29a/0x800
[ 1020.368698] __blk_mq_sched_dispatch_requests+0x3db/0x5f0
[ 1020.371854] blk_mq_sched_dispatch_requests+0x29/0x70
[ 1020.374087] blk_mq_run_work_fn+0x76/0x1b0
[ 1020.375750] process_one_work+0x211/0x630
[ 1020.377379] worker_thread+0x184/0x330
[ 1020.378949] kthread+0x10d/0x250
[ 1020.380296] ret_from_fork+0x29a/0x300
[ 1020.381855] ret_from_fork_asm+0x1a/0x30
[ 1020.383420]
-> #3 (set->srcu){.+.+}-{0:0}:
[ 1020.385477] __synchronize_srcu+0x49/0x170
[ 1020.387169] elevator_switch+0xc9/0x330
[ 1020.388763] elevator_change+0x128/0x1c0
[ 1020.390336] elevator_set_none+0x4c/0x90
[ 1020.391943] blk_unregister_queue+0xa8/0x110
[ 1020.393693] __del_gendisk+0x14e/0x3c0
[ 1020.395222] del_gendisk+0x75/0xa0
[ 1020.396709] nvme_ns_remove+0xf2/0x230 [nvme_core]
[ 1020.398634] nvme_remove_namespaces+0xf2/0x150 [nvme_core]
[ 1020.400808] nvme_do_delete_ctrl+0x71/0x90 [nvme_core]
[ 1020.402858] nvme_delete_ctrl_sync+0x3b/0x50 [nvme_core]
[ 1020.404958] nvme_sysfs_delete+0x34/0x40 [nvme_core]
[ 1020.406943] kernfs_fop_write_iter+0x16d/0x220
[ 1020.408790] vfs_write+0x37b/0x520
[ 1020.410197] ksys_write+0x67/0xe0
[ 1020.411580] do_syscall_64+0x76/0xb00
[ 1020.413084] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1020.415078]
-> #2 (&q->elevator_lock){+.+.}-{4:4}:
[ 1020.417365] __mutex_lock+0xa2/0x1150
[ 1020.418912] elevator_change+0xa8/0x1c0
[ 1020.420470] elv_iosched_store+0xdf/0x140
[ 1020.422116] kernfs_fop_write_iter+0x16d/0x220
[ 1020.424203] vfs_write+0x37b/0x520
[ 1020.425719] ksys_write+0x67/0xe0
[ 1020.427154] do_syscall_64+0x76/0xb00
[ 1020.428763] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1020.430891]
-> #1 (&q->q_usage_counter(io)){++++}-{0:0}:
[ 1020.433490] blk_alloc_queue+0x30e/0x350
[ 1020.435248] blk_mq_alloc_queue+0x61/0xd0
[ 1020.437010] scsi_alloc_sdev+0x2a0/0x3e0
[ 1020.438767] scsi_probe_and_add_lun+0x1bd/0x430
[ 1020.440724] __scsi_add_device+0x109/0x120
[ 1020.442488] ata_scsi_scan_host+0x97/0x1c0
[ 1020.444308] async_run_entry_fn+0x30/0x130
[ 1020.446112] process_one_work+0x211/0x630
[ 1020.447884] worker_thread+0x184/0x330
[ 1020.449562] kthread+0x10d/0x250
[ 1020.451013] ret_from_fork+0x29a/0x300
[ 1020.452698] ret_from_fork_asm+0x1a/0x30
[ 1020.454403]
-> #0 (fs_reclaim){+.+.}-{0:0}:
[ 1020.456559] __lock_acquire+0x1468/0x2210
[ 1020.458294] lock_acquire+0xd3/0x2f0
[ 1020.459935] fs_reclaim_acquire+0x99/0xd0
[ 1020.461712] kmem_cache_alloc_node_noprof+0x5a/0x770
[ 1020.463820] __alloc_skb+0x15f/0x190
[ 1020.465414] tcp_send_active_reset+0x3f/0x1e0
[ 1020.467374] tcp_disconnect+0x551/0x770
[ 1020.469116] __tcp_close+0x2c7/0x520
[ 1020.470742] tcp_close+0x20/0x80
[ 1020.472160] inet_release+0x34/0x60
[ 1020.473732] __sock_release+0x3d/0xc0
[ 1020.475346] sock_close+0x14/0x20
[ 1020.476842] __fput+0xf1/0x2c0
[ 1020.478204] delayed_fput+0x31/0x50
[ 1020.479788] process_one_work+0x211/0x630
[ 1020.481520] worker_thread+0x184/0x330
[ 1020.483206] kthread+0x10d/0x250
[ 1020.484683] ret_from_fork+0x29a/0x300
[ 1020.486284] ret_from_fork_asm+0x1a/0x30
[ 1020.488004]
other info that might help us debug this:
[ 1020.491063] Chain exists of:
fs_reclaim --> set->srcu --> sk_lock-AF_INET-NVME
[ 1020.494985] Possible unsafe locking scenario:
[ 1020.497262] CPU0 CPU1
[ 1020.499015] ---- ----
[ 1020.500790] lock(sk_lock-AF_INET-NVME);
[ 1020.502299] lock(set->srcu);
[ 1020.504444] lock(sk_lock-AF_INET-NVME);
[ 1020.507015] lock(fs_reclaim);
[ 1020.508242]
*** DEADLOCK ***
[ 1020.510524] 4 locks held by kworker/34:1/323:
[ 1020.512235] #0: ffff88810006af48 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x57a/0x630
[ 1020.515892] #1: ffffc90000c57e28 ((delayed_fput_work).work){+.+.}-{0:0}, at: process_one_work+0x1d0/0x630
[ 1020.519644] #2: ffff8881041da888 (&sb->s_type->i_mutex_key#10){+.+.}-{4:4}, at: __sock_release+0x30/0xc0
[ 1020.523309] #3: ffff888167d88e98 (sk_lock-AF_INET-NVME){+.+.}-{0:0}, at: tcp_close+0x15/0x80
[ 1020.526683]
stack backtrace:
[ 1020.528337] CPU: 34 UID: 0 PID: 323 Comm: kworker/34:1 Tainted: G N 6.18.0-rc4lblk+ #4 PREEMPT(voluntary)
[ 1020.528341] Tainted: [N]=TEST
[ 1020.528341] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014
[ 1020.528343] Workqueue: events delayed_fput
[ 1020.528345] Call Trace:
[ 1020.528348] <TASK>
[ 1020.528349] dump_stack_lvl+0x75/0xb0
[ 1020.528353] print_circular_bug+0x26a/0x330
[ 1020.528356] check_noncircular+0x12f/0x150
[ 1020.528359] __lock_acquire+0x1468/0x2210
[ 1020.528363] lock_acquire+0xd3/0x2f0
[ 1020.528365] ? kmem_cache_alloc_node_noprof+0x5a/0x770
[ 1020.528368] fs_reclaim_acquire+0x99/0xd0
[ 1020.528370] ? kmem_cache_alloc_node_noprof+0x5a/0x770
[ 1020.528371] kmem_cache_alloc_node_noprof+0x5a/0x770
[ 1020.528372] ? __alloc_skb+0x15f/0x190
[ 1020.528375] ? __alloc_skb+0x15f/0x190
[ 1020.528376] __alloc_skb+0x15f/0x190
[ 1020.528378] tcp_send_active_reset+0x3f/0x1e0
[ 1020.528381] tcp_disconnect+0x551/0x770
[ 1020.528383] __tcp_close+0x2c7/0x520
[ 1020.528386] tcp_close+0x20/0x80
[ 1020.528388] inet_release+0x34/0x60
[ 1020.528390] __sock_release+0x3d/0xc0
[ 1020.528393] sock_close+0x14/0x20
[ 1020.528394] __fput+0xf1/0x2c0
[ 1020.528396] delayed_fput+0x31/0x50
[ 1020.528397] process_one_work+0x211/0x630
[ 1020.528400] worker_thread+0x184/0x330
[ 1020.528402] ? __pfx_worker_thread+0x10/0x10
[ 1020.528403] kthread+0x10d/0x250
[ 1020.528405] ? __pfx_kthread+0x10/0x10
[ 1020.528407] ret_from_fork+0x29a/0x300
[ 1020.528408] ? __pfx_kthread+0x10/0x10
[ 1020.528409] ret_from_fork_asm+0x1a/0x30
[ 1020.528414] </TASK>
[ 1020.610038] nvme nvme0: mapped 48/0/0 default/read/poll queues.
[ 1020.620528] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 1020.652457] block nvme0n1: no available path - failing I/O
[ 1020.656167] block nvme0n1: no available path - failing I/O
[ 1020.659759] buffer_io_error: 42 callbacks suppressed
[ 1020.659762] Buffer I/O error on dev nvme0n1, logical block 0, async page read
[ 1021.656555] Key type psk unregistered
[ 1021.878341] Key type psk registered
More information about the Linux-nvme
mailing list