New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

cephfs: fix mount point break off problem after mds switch occured #14267

Merged
merged 1 commit into from Apr 15, 2017

Conversation

Projects
None yet
4 participants
@yunfeiguan

yunfeiguan commented Mar 31, 2017

The hot-standby become active as we expected but the mount piont broken strangely when the active mds is down. The root reason is the new mds use last_cap_renews decoded from ESesson::replay in find_idle_sessions and wrongly killed the session. Maybe we should reset session->last_cap_renew to the current time when server send OPEN to client in reconnect stage.

@yunfeiguan yunfeiguan changed the title from cephfs: try to solve the problem mount point break off when multi mds switch occurs to cephfs: fix mount point break off problem after mds switch occured Mar 31, 2017

@yunfeiguan

This comment has been minimized.

yunfeiguan commented Mar 31, 2017

@jcsp please help to review this, thank you!

@jcsp jcsp self-requested a review Mar 31, 2017

@jcsp

This comment has been minimized.

Contributor

jcsp commented Mar 31, 2017

So usually the client sends a renewcaps right after opening the session, and the MDS doesn't start evicting idle sessions until it reaches the clientreplay state. But I guess there's nothing to guarantee that, so we had a race here? Still, usually proceeding through the MDS states takes several seconds due to mdsmap updates on the mons, so I'm surprised an MDS ever reached clientreplay before it recieved its first renewcaps from the client.

I'd be interested to see a log of the case where it is incorrectly evicting a client, as it seems like kind of an unlikely race.

@yunfeiguan

This comment has been minimized.

yunfeiguan commented Apr 1, 2017

Okay, thank you for answering me, to tell the truth, this my first commit to open source community and i feel so cool, haha.
my test env based on ceph-10.2.2. Two mds, one atcive, the other is hot-standy.
From the logs posted below, i summarize the event timing sequence :
1.mds.xt1:active, mds.xt2:hot-standby . client.590301 open one session(ceph-fuse mount) . the open ESession was written to the journal by mds.xt1
2.mds.xt2:hot-standby ESession::replay load the session from journal and set session->last_cap_renew to current time (22:36:45.812140)
3.after running for a while (duration about 6 min). At time 22:42:57.234956, kill mds.xt1to let mds.xt2 be the active one which start standy-replay->replay->reconnect->clientreplay (at time 22:43:01.955607 ).
Meanwhile, fild_stale_session kicked in and find the client.590301 session->last_cap_renew(22:36:45.812140) is behind 376.142601s now(22:43:01.955607), so regard it as the stale session and being falsefully closed.
4. client side renewcaps (it was sent by client tick thread or handle_client_session CEPH_SESSION_OPEN)request come at 22:43:01.959210,since the session was killed at 22:43:01.955607, do nothing just returned.

the root cause the lattest session->last_cap_renew was set by ESession::replay during standby-replay that was so laggy behind the current time.
So,We should keep the session->last_cap_renew up to date during the hot-standy mds trying to become active.
it seems natural to update the last_cap_renew right after the mds server accepted the according session reconnect req.

2017-03-30 22:36:45.812142 7f99147d9700 1 mds.0.journal ESession::replay after get_or_add_session last_cap_renew is 2017-03-30 22:36:45.812140 session is client.590301 192.168.10.9:0/626254714 session addr 0x7f992c86b180
2017-03-30 22:36:45.812204 7f99147d9700 1 mds.0.0 replay_done (as standby)
2017-03-30 22:36:46.812769 7f9918be5700 1 mds.0.0 standby_replay_restart (as standby)
...
2017-03-30 22:42:59.589358 7f991b4eb700 1 mds.0.25448 handle_mds_map i am now mds.0.25448
2017-03-30 22:42:59.589361 7f991b4eb700 1 mds.0.25448 handle_mds_map state change up:reconnect --> up:rejoin
2017-03-30 22:42:59.589368 7f991b4eb700 1 mds.0.25448 rejoin_start
2017-03-30 22:42:59.600436 7f991b4eb700 1 mds.0.25448 rejoin_joint_start
2017-03-30 22:43:00.545873 7f9916be1700 1 mds.0.25448 rejoin_done
2017-03-30 22:43:00.728863 7f991b4eb700 1 mds.0.25448 handle_mds_map i am now mds.0.25448
2017-03-30 22:43:00.728874 7f991b4eb700 1 mds.0.25448 handle_mds_map state change up:rejoin --> up:clientreplay
2017-03-30 22:43:00.728882 7f991b4eb700 1 mds.0.25448 recovery_done -- successful recovery!
2017-03-30 22:43:00.729529 7f991b4eb700 1 mds.0.25448 clientreplay_start
...
2017-03-30 22:43:00.841273 7f99173e2700 1 mds.0.25448 queue_one_replay active requests counts: 638
2017-03-30 22:43:01.954731 7f9918be5700 1 mds.0.25448 MDSRank tick in state 12 will find_idle_sessions
2017-03-30 22:43:01.954744 7f9918be5700 1 mds.0.server new stale session client.590301 192.168.10.9:0/626254714 last 2017-03-30 22:36:45.812140
2017-03-30 22:43:01.955607 7f9918be5700 0 log_channel(cluster) log [INF] : closing stale session client.590301 192.168.10.9:0/626254714 after 376.142601

2017-03-30 22:43:01.959201 7f991b4eb700 1 mds.0.server enter handle_client_session client_session(request_renewcaps seq 22) v1 from client.590301
2017-03-30 22:43:01.959210 7f991b4eb700 1 mds.0.server renewcaps session client.590301 192.168.10.9:0/626254714 state is 5 session addr 0x7f992c86b180

@ukernel

This comment has been minimized.

Member

ukernel commented Apr 5, 2017

client does not send renewcaps right after reconnect. It sends renewcaps every 20 seconds by default. This issue can happen if the mds recovery is fast

@ukernel ukernel self-requested a review Apr 5, 2017

@ukernel

ukernel approved these changes Apr 5, 2017

please squash commits to one

YunfeiGuan
cephfs: fix mount point break off problem after mds switch occured
The hot-standby become active as we expected but the mount piont broken strangely
when the active mds is down. The root reason is the new mds use last_cap_renews
decoded from ESesson::replay in find_idle_sessions and wrongly killed the session.
Maybe we should reset session->last_cap_renew to the current time when server send
OPEN to client in reconnect stage.

Fixes: http://tracker.ceph.com/issues/19437
Signed-off-by: Guan yunfei <yunfei.guan@xtaotech.com>
@yunfeiguan

This comment has been minimized.

yunfeiguan commented Apr 10, 2017

@ukernel I have pushed the final version of my change, thank you.

@jcsp

This comment has been minimized.

Contributor

jcsp commented Apr 15, 2017

retest this please (jenkins)

@jcsp jcsp merged commit 4314e3d into ceph:master Apr 15, 2017

3 checks passed

Signed-off-by all commits in this PR are signed
Details
Unmodifed Submodules submodules for project are unmodified
Details
default Build finished.
Details
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment