Re: [PATCH] ceph: make sure the mdsc->mutex is nested in s->s_mutex to fix dead lock

[Jeff Layton <jlayton@kernel.org>]

On Wed, 2020-05-20 at 03:51 -0400, xiubli@redhat.com wrote:
> From: Xiubo Li <xiubli@redhat.com>
> 
> The call trace:
> 
> <6>[15981.740583] libceph: mon2 (1)10.72.36.245:40083 session lost, hunting for new mon
> <3>[16097.960293] INFO: task kworker/18:1:32111 blocked for more than 122 seconds.
> <3>[16097.960860]       Tainted: G            E     5.7.0-rc5+ #80
> <3>[16097.961332] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> <6>[16097.961868] kworker/18:1    D    0 32111      2 0x80004080
> <6>[16097.962151] Workqueue: ceph-msgr ceph_con_workfn [libceph]
> <4>[16097.962188] Call Trace:
> <4>[16097.962353]  ? __schedule+0x276/0x6e0
> <4>[16097.962359]  ? schedule+0x40/0xb0
> <4>[16097.962364]  ? schedule_preempt_disabled+0xa/0x10
> <4>[16097.962368]  ? __mutex_lock.isra.8+0x2b5/0x4a0
> <4>[16097.962460]  ? kick_requests+0x21/0x100 [ceph]
> <4>[16097.962485]  ? ceph_mdsc_handle_mdsmap+0x19c/0x5f0 [ceph]
> <4>[16097.962503]  ? extra_mon_dispatch+0x34/0x40 [ceph]
> <4>[16097.962523]  ? extra_mon_dispatch+0x34/0x40 [ceph]
> <4>[16097.962580]  ? dispatch+0x77/0x930 [libceph]
> <4>[16097.962602]  ? try_read+0x78b/0x11e0 [libceph]
> <4>[16097.962619]  ? __switch_to_asm+0x40/0x70
> <4>[16097.962623]  ? __switch_to_asm+0x34/0x70
> <4>[16097.962627]  ? __switch_to_asm+0x40/0x70
> <4>[16097.962631]  ? __switch_to_asm+0x34/0x70
> <4>[16097.962635]  ? __switch_to_asm+0x40/0x70
> <4>[16097.962654]  ? ceph_con_workfn+0x130/0x5e0 [libceph]
> <4>[16097.962713]  ? process_one_work+0x1ad/0x370
> <4>[16097.962717]  ? worker_thread+0x30/0x390
> <4>[16097.962722]  ? create_worker+0x1a0/0x1a0
> <4>[16097.962737]  ? kthread+0x112/0x130
> <4>[16097.962742]  ? kthread_park+0x80/0x80
> <4>[16097.962747]  ? ret_from_fork+0x35/0x40
> <3>[16097.962758] INFO: task kworker/25:1:1747 blocked for more than 122 seconds.
> <3>[16097.963233]       Tainted: G            E     5.7.0-rc5+ #80
> <3>[16097.963792] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> <6>[16097.964298] kworker/25:1    D    0  1747      2 0x80004080
> <6>[16097.964325] Workqueue: ceph-msgr ceph_con_workfn [libceph]
> <4>[16097.964331] Call Trace:
> <4>[16097.964340]  ? __schedule+0x276/0x6e0
> <4>[16097.964344]  ? schedule+0x40/0xb0
> <4>[16097.964347]  ? schedule_preempt_disabled+0xa/0x10
> <4>[16097.964351]  ? __mutex_lock.isra.8+0x2b5/0x4a0
> <4>[16097.964376]  ? handle_reply+0x33f/0x6f0 [ceph]
> <4>[16097.964407]  ? dispatch+0xa6/0xbc0 [ceph]
> <4>[16097.964429]  ? read_partial_message+0x214/0x770 [libceph]
> <4>[16097.964449]  ? try_read+0x78b/0x11e0 [libceph]
> <4>[16097.964454]  ? __switch_to_asm+0x40/0x70
> <4>[16097.964458]  ? __switch_to_asm+0x34/0x70
> <4>[16097.964461]  ? __switch_to_asm+0x40/0x70
> <4>[16097.964465]  ? __switch_to_asm+0x34/0x70
> <4>[16097.964470]  ? __switch_to_asm+0x40/0x70
> <4>[16097.964489]  ? ceph_con_workfn+0x130/0x5e0 [libceph]
> <4>[16097.964494]  ? process_one_work+0x1ad/0x370
> <4>[16097.964498]  ? worker_thread+0x30/0x390
> <4>[16097.964501]  ? create_worker+0x1a0/0x1a0
> <4>[16097.964506]  ? kthread+0x112/0x130
> <4>[16097.964511]  ? kthread_park+0x80/0x80
> <4>[16097.964516]  ? ret_from_fork+0x35/0x40
> 
> URL: https://tracker.ceph.com/issues/45609
> Reported-by: "Yan, Zheng" <zyan@redhat.com>
> Signed-off-by: Xiubo Li <xiubli@redhat.com>
> ---
>  fs/ceph/mds_client.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
> index 6c283c5..0e0ab01 100644
> --- a/fs/ceph/mds_client.c
> +++ b/fs/ceph/mds_client.c
> @@ -3769,8 +3769,6 @@ static int encode_snap_realms(struct ceph_mds_client *mdsc,
>   * recovering MDS might have.
>   *
>   * This is a relatively heavyweight operation, but it's rare.
> - *
> - * called with mdsc->mutex held.
>   */
>  static void send_mds_reconnect(struct ceph_mds_client *mdsc,
>  			       struct ceph_mds_session *session)
> @@ -4024,7 +4022,9 @@ static void check_new_map(struct ceph_mds_client *mdsc,
>  			    oldstate != CEPH_MDS_STATE_STARTING)
>  				pr_info("mds%d recovery completed\n", s->s_mds);
>  			kick_requests(mdsc, i);
> +			mutex_unlock(&mdsc->mutex);
>  			mutex_lock(&s->s_mutex);
> +			mutex_lock(&mdsc->mutex);
>  			ceph_kick_flushing_caps(mdsc, s);
>  			mutex_unlock(&s->s_mutex);
>  			wake_up_session_caps(s, RECONNECT);


Good catch. Merged into testing branch.

Thanks!
-- 
Jeff Layton <jlayton@kernel.org>