On Wed, May 20, 2020 at 1:44 PM Jeff Layton <jlayton@xxxxxxxxxx> wrote: > > On Wed, 2020-05-20 at 03:51 -0400, xiubli@xxxxxxxxxx wrote: > > From: Xiubo Li <xiubli@xxxxxxxxxx> > > > > 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@xxxxxxxxxx> > > Signed-off-by: Xiubo Li <xiubli@xxxxxxxxxx> > > --- > > 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. These stack traces take up the entire screen and provide very little information. Since this is a simple lock ordering issue, could they be replaced with a short description and perhaps a reference to mds_client.h where lock dependencies are documented? Thanks, Ilya
