On 2020/5/27 21:47, Jeff Layton wrote:
On Wed, 2020-05-27 at 20:47 +0800, Xiubo Li wrote:
On 2020/5/27 20:25, Ilya Dryomov wrote:
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?
Hmm, it makes sense.
Should I post a V2 ? Or will Jeff do the fix on the testing branch ?
I went ahead and just fixed it in the testing branch. Let me know if you want to revise the verbiage.
That looks good to me.
Thanks Jeff.
BRs
Xiubo