[bug report] WARNING: possible circular locking dependency detected with blktests nvme-tcp nvme/013
Sagi Grimberg
sagi at grimberg.me
Wed Sep 29 04:06:15 PDT 2021
> Hello
>
> Bellow warning was triggered with blktests nvme-tcp on latest
> 5.15.0-rc3, pls help check it.
Hey Yi, thanks for reporting..
I'm trying to understand the circular locking here. I'm trying to
understand if this is due to having an allocation in the
network send path that may cause a circular dependency.
>
> [ 2153.718873] run blktests nvme/013 at 2021-09-28 07:14:57
> [ 2154.082894] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
> [ 2154.116627] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
> [ 2154.174352] nvmet: creating controller 1 for subsystem
> blktests-subsystem-1 for NQN
> nqn.2014-08.org.nvmexpress:uuid:c83e4244a1d04d318ced2447da679f67.
> [ 2154.196889] nvme nvme0: creating 40 I/O queues.
> [ 2154.222389] nvme nvme0: mapped 40/0/0 default/read/poll queues.
> [ 2154.275779] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr
> 127.0.0.1:4420
> [ 2155.648483] XFS (nvme0n1): Mounting V5 Filesystem
> [ 2155.717630] XFS (nvme0n1): Ending clean mount
> [ 2155.734834] xfs filesystem being mounted at /mnt/blktests supports
> timestamps until 2038 (0x7fffffff)
>
> [ 2155.932675] ======================================================
> [ 2155.939575] WARNING: possible circular locking dependency detected
> [ 2155.946467] 5.15.0-rc3 #1 Not tainted
> [ 2155.950551] ------------------------------------------------------
> [ 2155.957447] fio/1496 is trying to acquire lock:
> [ 2155.962504] ffff93d58ffe2470 (sk_lock-AF_INET){+.+.}-{0:0}, at:
> tcp_sendpage+0x23/0x80
> [ 2155.971355]
> but task is already holding lock:
> [ 2155.977866] ffff93d59bb7f8f0 (&xfs_dir_ilock_class/5){+.+.}-{3:3},
> at: xfs_ilock+0xcf/0x290 [xfs]
> [ 2155.987885]
> which lock already depends on the new lock.
>
> [ 2155.997012]
> the existing dependency chain (in reverse order) is:
> [ 2156.005362]
> -> #3 (&xfs_dir_ilock_class/5){+.+.}-{3:3}:
> [ 2156.012843] down_write_nested+0x49/0x120
> [ 2156.017904] xfs_ilock+0xcf/0x290 [xfs]
> [ 2156.022850] xfs_create+0x1e8/0x660 [xfs]
> [ 2156.027989] xfs_generic_create+0xfa/0x340 [xfs]
> [ 2156.033805] vfs_mkdir+0x12b/0x1e0
> [ 2156.038194] do_mkdirat+0x10a/0x130
> [ 2156.042669] __x64_sys_mkdir+0x48/0x70
> [ 2156.047434] do_syscall_64+0x3b/0x90
> [ 2156.052013] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 2156.058238]
> -> #2 (sb_internal){.+.+}-{0:0}:
> [ 2156.064654] xfs_trans_alloc+0x1a1/0x3c0 [xfs]
> [ 2156.070281] xfs_vn_update_time+0xc6/0x260 [xfs]
> [ 2156.076097] touch_atime+0x129/0x230
> [ 2156.080672] xfs_file_mmap+0x84/0x90 [xfs]
> [ 2156.085906] mmap_region+0x497/0x6b0
> [ 2156.090480] do_mmap+0x362/0x560
> [ 2156.094663] vm_mmap_pgoff+0xb8/0x150
> [ 2156.099330] ksys_mmap_pgoff+0x198/0x1f0
> [ 2156.104288] do_syscall_64+0x3b/0x90
> [ 2156.108860] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 2156.115078]
> -> #1 (&mm->mmap_lock#2){++++}-{3:3}:
> [ 2156.121978] __might_fault+0x56/0x80
> [ 2156.126553] _copy_from_user+0x20/0xa0
> [ 2156.131327] ip_setsockopt+0x123d/0x15c0
> [ 2156.136287] __sys_setsockopt+0xba/0x1a0
> [ 2156.141250] __x64_sys_setsockopt+0x1b/0x20
> [ 2156.146499] do_syscall_64+0x3b/0x90
> [ 2156.151069] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 2156.157289]
> -> #0 (sk_lock-AF_INET){+.+.}-{0:0}:
> [ 2156.164093] __lock_acquire+0x11fe/0x1e00
> [ 2156.169154] lock_acquire+0xc4/0x2e0
> [ 2156.173727] lock_sock_nested+0x2e/0x80
> [ 2156.178593] tcp_sendpage+0x23/0x80
> [ 2156.183068] inet_sendpage+0x4f/0x80
> [ 2156.187645] kernel_sendpage+0x62/0xf0
> [ 2156.192413] nvme_tcp_try_send+0x128/0x810 [nvme_tcp]
> [ 2156.198633] nvme_tcp_queue_rq+0x35a/0x380 [nvme_tcp]
> [ 2156.204853] __blk_mq_try_issue_directly+0x120/0x1c0
> [ 2156.210983] blk_mq_try_issue_list_directly+0x157/0x250
> [ 2156.217400] blk_mq_sched_insert_requests+0x241/0x2a0
> [ 2156.223620] blk_mq_flush_plug_list+0x114/0x210
> [ 2156.229256] blk_finish_plug+0x21/0x30
> [ 2156.234028] _xfs_buf_ioapply+0x30a/0x3c0 [xfs]
> [ 2156.239747] __xfs_buf_submit+0x92/0x260 [xfs]
> [ 2156.245360] xfs_buf_read_map+0xe9/0x2a0 [xfs]
> [ 2156.250969] xfs_trans_read_buf_map+0x1bb/0x550 [xfs]
> [ 2156.257274] xfs_btree_read_buf_block.constprop.0+0x75/0xb0 [xfs]
> [ 2156.264732] xfs_btree_lookup_get_block+0x87/0x160 [xfs]
> [ 2156.271316] xfs_btree_lookup+0x123/0x4d0 [xfs]
> [ 2156.277027] xfs_dialloc_ag_update_inobt+0x3a/0x180 [xfs]
> [ 2156.283709] xfs_dialloc+0x43f/0x800 [xfs]
> [ 2156.288938] xfs_create+0x404/0x660 [xfs]
> [ 2156.294075] xfs_generic_create+0xfa/0x340 [xfs]
> [ 2156.299891] lookup_open.isra.0+0x537/0x670
> [ 2156.305141] path_openat+0x2aa/0xa20
> [ 2156.309713] do_filp_open+0x9f/0x130
> [ 2156.314290] do_sys_openat2+0x7a/0x140
> [ 2156.319057] __x64_sys_openat+0x45/0x70
> [ 2156.323918] do_syscall_64+0x3b/0x90
> [ 2156.328491] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 2156.334712]
> other info that might help us debug this:
>
> [ 2156.343644] Chain exists of:
> sk_lock-AF_INET --> sb_internal --> &xfs_dir_ilock_class/5
>
> [ 2156.355972] Possible unsafe locking scenario:
>
> [ 2156.362579] CPU0 CPU1
> [ 2156.367632] ---- ----
> [ 2156.372685] lock(&xfs_dir_ilock_class/5);
> [ 2156.377351] lock(sb_internal);
> [ 2156.383764] lock(&xfs_dir_ilock_class/5);
> [ 2156.391242] lock(sk_lock-AF_INET);
> [ 2156.395230]
> *** DEADLOCK ***
>
> [ 2156.401834] 6 locks held by fio/1496:
> [ 2156.405919] #0: ffff93d584c36498 (sb_writers#13){.+.+}-{0:0}, at:
> path_openat+0x9fc/0xa20
> [ 2156.415147] #1: ffff93d59bb7fb30
> (&inode->i_sb->s_type->i_mutex_dir_key){++++}-{3:3}, at:
> path_openat+0x296/0xa20
> [ 2156.426693] #2: ffff93d584c366b8 (sb_internal){.+.+}-{0:0}, at:
> xfs_trans_alloc_icreate+0x41/0xd0 [xfs]
> [ 2156.437363] #3: ffff93d59bb7f8f0
> (&xfs_dir_ilock_class/5){+.+.}-{3:3}, at: xfs_ilock+0xcf/0x290 [xfs]
> [ 2156.447838] #4: ffff93d5d75f4c60 (hctx->srcu){....}-{0:0}, at:
> hctx_lock+0x51/0xd0
> [ 2156.456386] #5: ffff93d59d7bc3f0 (&queue->send_mutex){+.+.}-{3:3},
> at: nvme_tcp_queue_rq+0x33e/0x380 [nvme_tcp]
> [ 2156.467748]
> stack backtrace:
> [ 2156.472612] CPU: 27 PID: 1496 Comm: fio Not tainted 5.15.0-rc3 #1
> [ 2156.479410] Hardware name: Intel Corporation S2600CP/S2600CP, BIOS
> RMLSDP.86I.R3.27.D685.1305151734 05/15/2013
> [ 2156.490578] Call Trace:
> [ 2156.493312] dump_stack_lvl+0x57/0x72
> [ 2156.497404] check_noncircular+0xdf/0x100
> [ 2156.501879] ? usage_match+0x20/0x20
> [ 2156.505867] ? __bfs+0xf5/0x230
> [ 2156.509373] __lock_acquire+0x11fe/0x1e00
> [ 2156.513850] lock_acquire+0xc4/0x2e0
> [ 2156.517829] ? tcp_sendpage+0x23/0x80
> [ 2156.521917] lock_sock_nested+0x2e/0x80
> [ 2156.526199] ? tcp_sendpage+0x23/0x80
> [ 2156.530285] tcp_sendpage+0x23/0x80
> [ 2156.534179] inet_sendpage+0x4f/0x80
> [ 2156.538170] kernel_sendpage+0x62/0xf0
> [ 2156.542355] nvme_tcp_try_send+0x128/0x810 [nvme_tcp]
> [ 2156.547994] ? mutex_trylock+0x13f/0x160
> [ 2156.552374] ? nvme_tcp_queue_rq+0x33e/0x380 [nvme_tcp]
> [ 2156.558210] nvme_tcp_queue_rq+0x35a/0x380 [nvme_tcp]
> [ 2156.563850] __blk_mq_try_issue_directly+0x120/0x1c0
> [ 2156.569395] blk_mq_try_issue_list_directly+0x157/0x250
> [ 2156.575230] blk_mq_sched_insert_requests+0x241/0x2a0
> [ 2156.580869] blk_mq_flush_plug_list+0x114/0x210
> [ 2156.585926] blk_finish_plug+0x21/0x30
> [ 2156.590110] _xfs_buf_ioapply+0x30a/0x3c0 [xfs]
> [ 2156.595252] __xfs_buf_submit+0x92/0x260 [xfs]
> [ 2156.600295] xfs_buf_read_map+0xe9/0x2a0 [xfs]
> [ 2156.605335] xfs_trans_read_buf_map+0x1bb/0x550 [xfs]
> [ 2156.611060] ? xfs_btree_read_buf_block.constprop.0+0x75/0xb0 [xfs]
> [ 2156.618129] xfs_btree_read_buf_block.constprop.0+0x75/0xb0 [xfs]
> [ 2156.625006] xfs_btree_lookup_get_block+0x87/0x160 [xfs]
> [ 2156.631008] xfs_btree_lookup+0x123/0x4d0 [xfs]
> [ 2156.636137] ? rcu_read_lock_sched_held+0x3f/0x80
> [ 2156.641395] ? kmem_cache_alloc+0x28a/0x340
> [ 2156.646070] xfs_dialloc_ag_update_inobt+0x3a/0x180 [xfs]
> [ 2156.652172] xfs_dialloc+0x43f/0x800 [xfs]
> [ 2156.656822] ? lock_acquired+0xbc/0x380
> [ 2156.661104] xfs_create+0x404/0x660 [xfs]
> [ 2156.665663] xfs_generic_create+0xfa/0x340 [xfs]
> [ 2156.670900] lookup_open.isra.0+0x537/0x670
> [ 2156.675573] path_openat+0x2aa/0xa20
> [ 2156.679564] do_filp_open+0x9f/0x130
> [ 2156.683554] ? lock_release+0x28a/0x400
> [ 2156.687840] ? _raw_spin_unlock+0x1f/0x30
> [ 2156.692314] ? alloc_fd+0x12f/0x1f0
> [ 2156.696210] do_sys_openat2+0x7a/0x140
> [ 2156.700394] __x64_sys_openat+0x45/0x70
> [ 2156.704676] do_syscall_64+0x3b/0x90
> [ 2156.708658] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 2156.714297] RIP: 0033:0x7fcb40bc7584
> [ 2156.718290] Code: 24 20 eb 8f 66 90 44 89 54 24 0c e8 56 8b f8 ff
> 44 8b 54 24 0c 44 89 e2 48 89 ee 41 89 c0 bf 9c ff ff ff b8 01 01 00
> 00 0f 05 <48> 3d 00 f0 ff ff 77 34 44 89 c7 89 44 24 0c e8 98 8b f8 ff
> 8b 44
> [ 2156.739247] RSP: 002b:00007ffda2d2e600 EFLAGS: 00000293 ORIG_RAX:
> 0000000000000101
> [ 2156.747698] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fcb40bc7584
> [ 2156.755660] RDX: 0000000000000041 RSI: 00007fcb3fad72b0 RDI: 00000000ffffff9c
> [ 2156.763626] RBP: 00007fcb3fad72b0 R08: 0000000000000000 R09: 0000000000000000
> [ 2156.771591] R10: 00000000000001a4 R11: 0000000000000293 R12: 0000000000000041
> [ 2156.779553] R13: 0000000000000000 R14: 00007fcb3fad7110 R15: 000000003b600000
>
More information about the Linux-nvme
mailing list