Re: RE: [PATCH] Revert "ceph: when filling trace, call ceph_get_inode outside of mutexes"
From: 李磊
Date: Fri Apr 24 2026 - 14:56:04 EST
> 2026年4月25日 02:11，Viacheslav Dubeyko <Slava.Dubeyko@xxxxxxx> 写道：
>
> 安全提示：此邮件来自公司外部。除非您确认发件人身份可信且邮件内容不含可疑信息，否则请勿回复或转发邮件、点击邮件链接或打开附件。
>
>
> On Thu, 2026-04-23 at 19:50 +0000, Viacheslav Dubeyko wrote:
>> On Sat, 2026-04-18 at 12:12 +0800, Li Lei wrote:
>>> This reverts commit bca9fc14c70fcbbebc84954cc39994e463fb9468.
>>>
>>> Deadlock detected between mdsc->snap_rwsem and the I_NEW bit in
>>> handle_reply().
>>>
>>> - kworker/u113:1 (stat inode)
>>> 1) Hold a inode with I_NEW set
>>> 2) Request for mdsc->snap_rwsem
>>> - kworker/u113:2 (readdir)
>>> 1) Hold mdsc->snap_rwsem
>>> 2) Wait for inode I_NEW flag to be cleared
>>>
>>> task:kworker/u113:1 state:D stack: 0 pid:34454 ppid: 2
>>> flags:0x00004000
>>> Workqueue: ceph-msgr ceph_con_workfn [libceph]
>>> Call Trace:
>>> __schedule+0x3a9/0x8d0
>>> schedule+0x49/0xb0
>>> rwsem_down_write_slowpath+0x30a/0x5e0
>>> handle_reply+0x4d7/0x7f0 [ceph]
>>> ? ceph_tcp_recvmsg+0x6f/0xa0 [libceph]
>>> mds_dispatch+0x10a/0x690 [ceph]
>>> ? calc_signature+0xdf/0x110 [libceph]
>>> ? ceph_x_check_message_signature+0x58/0xc0 [libceph]
>>> ceph_con_process_message+0x73/0x140 [libceph]
>>> ceph_con_v1_try_read+0x2f2/0x860 [libceph]
>>> ceph_con_workfn+0x31e/0x660 [libceph]
>>> process_one_work+0x1cb/0x370
>>> worker_thread+0x30/0x390
>>> ? process_one_work+0x370/0x370
>>> kthread+0x13e/0x160
>>> ? set_kthread_struct+0x50/0x50
>>> ret_from_fork+0x1f/0x30
>>>
>>> task:kworker/u113:2 state:D stack: 0 pid:54267 ppid: 2
>>> flags:0x00004000
>>> Workqueue: ceph-msgr ceph_con_workfn [libceph]
>>> Call Trace:
>>> __schedule+0x3a9/0x8d0
>>> ? bit_wait_io+0x60/0x60
>>> ? bit_wait_io+0x60/0x60
>>> schedule+0x49/0xb0
>>> bit_wait+0xd/0x60
>>> __wait_on_bit+0x2a/0x90
>>> ? ceph_force_reconnect+0x90/0x90 [ceph]
>>> out_of_line_wait_on_bit+0x91/0xb0
>>> ? bitmap_empty+0x20/0x20
>>> ilookup5.part.29+0x69/0x90
>>> ? ceph_force_reconnect+0x90/0x90 [ceph]
>>> ? ceph_ino_compare+0x30/0x30 [ceph]
>>> iget5_locked+0x26/0x90
>>> ceph_get_inode+0x45/0x130 [ceph]
>>> ceph_readdir_prepopulate+0x59f/0xca0 [ceph]
>>> handle_reply+0x78d/0x7f0 [ceph]
>>> ? ceph_tcp_recvmsg+0x6f/0xa0 [libceph]
>>> mds_dispatch+0x10a/0x690 [ceph]
>>> ? calc_signature+0xdf/0x110 [libceph]
>>> ? ceph_x_check_message_signature+0x58/0xc0 [libceph]
>>> ceph_con_process_message+0x73/0x140 [libceph]
>>> ceph_con_v1_try_read+0x2f2/0x860 [libceph]
>>> ceph_con_workfn+0x31e/0x660 [libceph]
>>> process_one_work+0x1cb/0x370
>>> worker_thread+0x30/0x390
>>> ? process_one_work+0x370/0x370
>>> kthread+0x13e/0x160
>>> ? set_kthread_struct+0x50/0x50
>>> ret_from_fork+0x1f/0x30
>>>
>>> It's rather rear to be caught, but here's Fast Reproduce Steps
>>> (multiple mds is needed):
>>> 1. Try to find 2 different directories (DIR_a DIR_b) in a cephfs cluster
>>> and make sure they have different auth mds nodes. In this way, a client
>>> may have chances to run handle_reply on different CPU for our test
>>> (see step 5 and step 6).
>>> 2. In DIR_b, create a hard link of DIR_a/FILE_a, namely FILE_b.
>>> DIR_a/FILE_a and DIR_b/FILE_b have the same ino (123456 e.g)
>>> 3. Save ino in code below, make it sleep for stat command.
>>> ```
>>> static void handle_reply(struct ceph_mds_session
>>> *session, struct ceph_msg *msg)
>>> goto out_err;
>>> }
>>> req->r_target_inode = in;
>>> + if (in->i_ino == 123456) {
>>> + pr_err("inode %lu found, ready to wait 10 seconds.\n",
>>> + in->i_ino);
>>> + msleep(10000);
>>> + }
>>> ```
>>> 4. Execute echo 3 > /proc/sys/vm/drop_caches
>>> 5. In a shell, do `cd DIR_a;stat DIR_a/FILE_a`, we suppose to be stuck on this shell
>>> because of msleep() in handle_reply().
>>> 6. In the other shell, do `cd DIR_b;ls DIR_b/` to trigger ceph_readdir_prepopulate()
>>>
>>> Repeat step 4-6, less than 10 times is enough to see the problem.
>>>
>>> It turns out that commit bca9fc14c70f ("ceph: when filling trace, call ceph_get_inode outside of mutexes")
>>> moved ceph_inode_get outside snap_rmsem and made a chance for the deadlock of ceph_inode_get()
>>> and snap_rwsem.
>>>
>>> After the following commit, original commit(bca9fc14c70f) can be reverted safely.
>>> commit 6a92b08fdad2 ("ceph: don't take s_mutex or snap_rwsem in ceph_check_caps")
>>>
>>> Signed-off-by: Zhao Sun <sunzhao03@xxxxxxxxxxxx>
>>> Signed-off-by: Li Lei <lilei24@xxxxxxxxxxxx>
>>> ---
>>> fs/ceph/inode.c | 26 ++++++++++++++++++++++----
>>> fs/ceph/mds_client.c | 29 -----------------------------
>>> 2 files changed, 22 insertions(+), 33 deletions(-)
>>>
>>> diff --git a/fs/ceph/inode.c b/fs/ceph/inode.c
>>> index d99e12d..0c241a4 100644
>>> --- a/fs/ceph/inode.c
>>> +++ b/fs/ceph/inode.c
>>> @@ -1667,10 +1667,28 @@ int ceph_fill_trace(struct super_block *sb, struct ceph_mds_request *req)
>>> }
>>>
>>> if (rinfo->head->is_target) {
>>> - /* Should be filled in by handle_reply */
>>> - BUG_ON(!req->r_target_inode);
>>> + in = xchg(&req->r_new_inode, NULL);
>>> + tvino.ino = le64_to_cpu(rinfo->targeti.in->ino);
>>> + tvino.snap = le64_to_cpu(rinfo->targeti.in->snapid);
>>> +
>>> + /*
>>> + * If we ended up opening an existing inode, discard
>>> + * r_new_inode
>>> + */
>>> + if (req->r_op == CEPH_MDS_OP_CREATE &&
>>> + !req->r_reply_info.has_create_ino) {
>>> + /* This should never happen on an async create */
>>> + WARN_ON_ONCE(req->r_deleg_ino);
>>> + iput(in);
>>> + in = NULL;
>>> + }
>>> +
>>> + in = ceph_get_inode(fsc->sb, tvino, in);
>>> + if (IS_ERR(in)) {
>>> + err = PTR_ERR(in);
>>> + goto done;
>>> + }
>>>
>>> - in = req->r_target_inode;
>>> err = ceph_fill_inode(in, req->r_locked_page, &rinfo->targeti,
>>> NULL, session,
>>> (!test_bit(CEPH_MDS_R_ABORTED, &req->r_req_flags) &&
>>> @@ -1680,13 +1698,13 @@ int ceph_fill_trace(struct super_block *sb, struct ceph_mds_request *req)
>>> if (err < 0) {
>>> pr_err_client(cl, "badness %p %llx.%llx\n", in,
>>> ceph_vinop(in));
>>> - req->r_target_inode = NULL;
>>> if (inode_state_read_once(in) & I_NEW)
>>> discard_new_inode(in);
>>> else
>>> iput(in);
>>> goto done;
>>> }
>>> + req->r_target_inode = in;
>>> if (inode_state_read_once(in) & I_NEW)
>>> unlock_new_inode(in);
>>> }
>>> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
>>> index b174627..8a27775 100644
>>> --- a/fs/ceph/mds_client.c
>>> +++ b/fs/ceph/mds_client.c
>>> @@ -3941,36 +3941,7 @@ static void handle_reply(struct ceph_mds_session *session, struct ceph_msg *msg)
>>> session->s_con.peer_features);
>>> mutex_unlock(&mdsc->mutex);
>>>
>>> - /* Must find target inode outside of mutexes to avoid deadlocks */
>>> rinfo = &req->r_reply_info;
>>> - if ((err >= 0) && rinfo->head->is_target) {
>>> - struct inode *in = xchg(&req->r_new_inode, NULL);
>>> - struct ceph_vino tvino = {
>>> - .ino = le64_to_cpu(rinfo->targeti.in->ino),
>>> - .snap = le64_to_cpu(rinfo->targeti.in->snapid)
>>> - };
>>> -
>>> - /*
>>> - * If we ended up opening an existing inode, discard
>>> - * r_new_inode
>>> - */
>>> - if (req->r_op == CEPH_MDS_OP_CREATE &&
>>> - !req->r_reply_info.has_create_ino) {
>>> - /* This should never happen on an async create */
>>> - WARN_ON_ONCE(req->r_deleg_ino);
>>> - iput(in);
>>> - in = NULL;
>>> - }
>>> -
>>> - in = ceph_get_inode(mdsc->fsc->sb, tvino, in);
>>> - if (IS_ERR(in)) {
>>> - err = PTR_ERR(in);
>>> - mutex_lock(&session->s_mutex);
>>> - goto out_err;
>>> - }
>>> - req->r_target_inode = in;
>>> - }
>>> -
>>> mutex_lock(&session->s_mutex);
>>> if (err < 0) {
>>> pr_err_client(cl, "got corrupt reply mds%d(tid:%lld)\n",
>>
>> Let me run xfstests for the patch to double check that nothing is broken.
>>
>>
>
> Unexpectedly, I have a crash on generic/701 with your patch applied. I am going
> to re-run xfstests without your patch.
>
> generic/701 50s ... [failed, exit status 137]_check_dmesg: something found in
> dmesg (see xfstests-dev/results//generic/701.dmesg)
> - output mismatch (see xfstests-dev/results//generic/701.out.bad)
> --- tests/generic/701.out 2026-04-01 19:47:53.878452478 -0700
> +++ xfstests-dev/results//generic/701.out.bad 2026-04-24
> 04:57:37.887700953 -0700
> @@ -1,2 +1,3 @@
> QA output created by 701
> -Number of allocated blocks after truncate is in range
> +pwrite: Permission denied
> +./check: line 700: 311685 Killed systemd-run --quiet --
> unit "${unit}" --scope "${cmd[@]}"
> ...
> (Run 'diff -u xfstests-dev/tests/generic/701.out xfstests-
> dev/results//generic/701.out.bad' to see the entire diff)
>
> Apr 23 22:42:26 ssdfs-vm-test kernel: [29717.030383] ceph: [2bf3efd7-3e1c-453d-
> 9665-3c75a0dc96dd 19499]: mds0 caps stale
> Apr 23 22:43:18 ssdfs-vm-test kernel: [29733.938331] INFO: task
> kworker/u32:0:241092 blocked for more than 122 seconds.
> Apr 23 22:43:25 ssdfs-vm-test kernel: [29733.940727] Not tainted 7.0.0+ #9
> Apr 23 22:43:25 ssdfs-vm-test kernel: [29733.941449] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Apr 23 22:43:25 ssdfs-vm-test kernel: [29733.942756] task:kworker/u32:0
> state:D stack:0 pid:241092 tgid:241092 ppid:2 task_flags:0x4208060
> flags:0x00080000
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942773] Workqueue: writeback
> wb_workfn (flush-ceph-766)
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942792] Call Trace:
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942795] <TASK>
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942803] __schedule+0x5b7/0x1fe0
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942812] ? lock_acquire+0xc8/0x2f0
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942819] ? schedule+0xb1/0x180
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942823] ? find_held_lock+0x31/0x90
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942829] ? schedule+0x10e/0x180
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942834] ? lock_release+0xd9/0x300
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942842] schedule+0x3a/0x180
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942847]
> schedule_preempt_disabled+0x15/0x30
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942851] __mutex_lock+0x777/0x1220
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942858] ? ceph_con_send+0x4c/0x250
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942876]
> mutex_lock_nested+0x1b/0x30
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.942881] ?
> mutex_lock_nested+0x1b/0x30
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943136] ceph_con_send+0x4c/0x250
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943146] ? lock_acquire+0xc8/0x2f0
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943158] send_request+0x7d0/0xcc0
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943174] ?
> do_raw_spin_unlock+0x4e/0xe0
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943182] ?
> _raw_spin_unlock+0x22/0x50
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943222]
> __submit_request+0x2a9/0x4c0
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943236]
> ceph_osdc_start_request+0x6c/0x90
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943245]
> ceph_writepages_start+0x101b/0x21e0
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943254] ?
> __lock_acquire+0x4a2/0x2650
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943331] do_writepages+0xc2/0x170
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943338] ? do_writepages+0xc2/0x170
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943342] ? lock_release+0xd9/0x300
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943347] ?
> writeback_sb_inodes+0x1e7/0x900
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943358]
> __writeback_single_inode+0x5a/0x5e0
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943365] ?
> _raw_spin_unlock+0x22/0x50
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943377]
> writeback_sb_inodes+0x29f/0x900
> Apr 23 22:43:26 ssdfs-vm-test kernel: [29733.943435]
> __writeback_inodes_wb+0x54/0xf0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943448] wb_writeback+0x3df/0x470
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943473] wb_workfn+0x364/0x520
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943493]
> process_one_work+0x22f/0x620
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943515] worker_thread+0x1e2/0x400
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943525] ?
> __pfx_worker_thread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943532] kthread+0x109/0x140
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943539] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943548] ret_from_fork+0x3e1/0x470
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943556] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943561] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943568]
> ret_from_fork_asm+0x1a/0x30
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943595] </TASK>
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.943669] INFO: task
> kworker/u32:0:241092 is blocked on a mutex likely owned by task
> kworker/7:4:308292.
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953769] task:kworker/7:4
> state:R running task stack:0 pid:308292 tgid:308292 ppid:2
> task_flags:0x4208860 flags:0x00080000
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953786] Workqueue: ceph-msgr
> ceph_con_workfn
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953795] Call Trace:
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953798] <TASK>
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953805] __schedule+0x5b7/0x1fe0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953809] ?
> irqentry_exit+0x299/0x740
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953843] ?
> sysvec_apic_timer_interrupt+0x54/0xd0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953858] preempt_schedule+0x4c/0x80
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953862]
> preempt_schedule_thunk+0x16/0x30
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953874]
> _raw_spin_unlock_irq+0x4f/0x70
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953880] evict_folios+0x394/0xf00
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953886] ?
> hrtimer_start_range_ns+0x270/0x980
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953904] ?
> lock_is_held_type+0xaa/0x140
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953916]
> try_to_shrink_lruvec+0x1a9/0x3b0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953934] shrink_one+0xd1/0x1c0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953943] shrink_node+0xba8/0x13d0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953954] ? shrink_node+0xb7e/0x13d0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953969]
> do_try_to_free_pages+0xc1/0x4f0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953974] ?
> do_try_to_free_pages+0xc1/0x4f0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953984]
> try_to_free_pages+0xe0/0x310
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.953989] ?
> fs_reclaim_acquire+0x4f/0x100
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954009]
> __alloc_frozen_pages_noprof+0xd49/0x1830
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954017] ?
> ip_dst_mtu_maybe_forward.constprop.0+0x24/0x2a0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954034] ? lock_acquire+0xc8/0x2f0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954039] ?
> __virt_addr_valid+0xf5/0x340
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954053] ?
> policy_nodemask+0x122/0x1d0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954064]
> alloc_pages_mpol+0xba/0x1a0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954069] ?
> _copy_from_iter+0x273/0x790
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954080]
> alloc_pages_noprof+0x59/0xe0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954087]
> skb_page_frag_refill+0xc4/0xf0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954093]
> sk_page_frag_refill+0x21/0xc0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954099]
> tcp_sendmsg_locked+0x848/0x14e0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954122] tcp_sendmsg+0x30/0x60
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954128] inet_sendmsg+0x46/0x90
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954135] sock_sendmsg+0xf1/0x100
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954142] ? kfree+0x3ab/0x560
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954147] ?
> __free_frozen_pages+0x6e0/0x730
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954157] ? sg_free_table+0x39/0x90
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954167] do_sendmsg+0x8d/0xe0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954197]
> ceph_con_v2_try_write+0x99/0x560
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954206]
> ceph_con_workfn+0x17f/0x820
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954215]
> process_one_work+0x22f/0x620
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954221] ?
> process_one_work+0x254/0x620
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954252] worker_thread+0x1e2/0x400
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954260] ?
> __pfx_worker_thread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954265] kthread+0x109/0x140
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954271] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954278] ret_from_fork+0x3e1/0x470
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954283] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954287] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954293]
> ret_from_fork_asm+0x1a/0x30
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954314] </TASK>
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.954321] INFO: task
> kworker/7:2:299107 blocked for more than 122 seconds.
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.955829] Not tainted 7.0.0+ #9
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.959909] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961590] task:kworker/7:2
> state:D stack:0 pid:299107 tgid:299107 ppid:2 task_flags:0x4208060
> flags:0x00080000
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961598] Workqueue: events
> delayed_work
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961607] Call Trace:
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961610] <TASK>
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961618] __schedule+0x5b7/0x1fe0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961622] ?
> mark_held_locks+0x46/0x90
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961629] ? find_held_lock+0x31/0x90
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961634] ? schedule+0x10e/0x180
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961639] ? lock_release+0xd9/0x300
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961649] schedule+0x3a/0x180
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961653]
> schedule_preempt_disabled+0x15/0x30
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961658]
> rwsem_down_read_slowpath+0x27b/0x6c0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961662] ?
> ceph_send_cap_releases+0x4b/0x370
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961672] ?
> __queue_delayed_work+0x134/0x190
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961682] down_read+0x7c/0x190
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961687]
> ceph_send_cap_releases+0x4b/0x370
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961692] ?
> ceph_con_send+0x1e8/0x250
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961705] delayed_work+0x1d8/0x2b0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961715]
> process_one_work+0x22f/0x620
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961730] worker_thread+0x1e2/0x400
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961738] ?
> __pfx_worker_thread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961744] kthread+0x109/0x140
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961749] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961756] ret_from_fork+0x3e1/0x470
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961787] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961791] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961797]
> ret_from_fork_asm+0x1a/0x30
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961818] </TASK>
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.961851] INFO: task
> kworker/7:2:299107 <reader> blocked on an rw-semaphore likely owned by task
> kworker/u32:0:241092 <reader>
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.972571] INFO: task
> kworker/7:5:309930 blocked for more than 122 seconds.
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.973737] Not tainted 7.0.0+ #9
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.974413] "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978473] task:kworker/7:5
> state:D stack:0 pid:309930 tgid:309930 ppid:2 task_flags:0x4208060
> flags:0x00080000
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978479] Workqueue: events
> handle_osds_timeout
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978485] Call Trace:
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978487] <TASK>
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978493] __schedule+0x5b7/0x1fe0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978496] ?
> mark_held_locks+0x46/0x90
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978502] ? find_held_lock+0x31/0x90
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978506] ? schedule+0x10e/0x180
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978509] ? lock_release+0xd9/0x300
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978537] schedule+0x3a/0x180
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978540]
> schedule_preempt_disabled+0x15/0x30
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978543]
> rwsem_down_write_slowpath+0x1f3/0x990
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978547] ? lock_acquire+0xc8/0x2f0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978556] ?
> process_one_work+0x1ef/0x620
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978563] down_write+0xe4/0xf0
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978567]
> handle_osds_timeout+0x45/0x160
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978573]
> process_one_work+0x22f/0x620
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978585] worker_thread+0x1e2/0x400
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978591] ?
> __pfx_worker_thread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978595] kthread+0x109/0x140
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978599] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978604] ret_from_fork+0x3e1/0x470
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978608] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978611] ? __pfx_kthread+0x10/0x10
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978615]
> ret_from_fork_asm+0x1a/0x30
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978631] </TASK>
> Apr 23 22:43:30 ssdfs-vm-test kernel: [29733.978653] INFO: task
> kworker/7:5:309930 <writer> blocked on an rw-semaphore likely owned by task
> kworker/u32:0:241092 <reader>
>
> I am not completely sure that your patch is responsible.
Thanks for the double check and sorry for the inconvenience.
I’ll recheck the patch and take more stress tests.
Thanks