Ceph » CephFS

Another MDS have no problem reconnecting to client:

2014-05-06 18:16:09.441894 7f2ac5567700  1 mds.0.server reconnect_clients -- 3 sessions
2014-05-06 18:16:09.443429 7f2ac5567700  0 log [DBG] : reconnect by new client.2311588 192.168.0.7:0/9222 after 0.000021

Many thanks, Zheng. Looks like it is commit commit:09a1bc5.

I'm sorry to say that commit:09a1bc5 did not fix it.
I cherry-picked it to 0.80 and here how it looks in MDS log:

2014-05-11 09:57:58.152628 7fe9f87b6700  0 auth: could not find secret_id=2895
2014-05-11 09:57:58.152634 7fe9f87b6700  0 cephx: verify_authorizer could not get service secret for service mds secret_id=2895
2014-05-11 09:57:58.152637 7fe9f87b6700  0 -- 192.168.0.2:6800/25496 >> 192.168.0.7:0/2446 pipe(0x7fea50d3db80 sd=28 :6800 s=0 pgs=0 cs=0 l=0 c=0x7fea03f6a2c0).accept: got bad authorizer
2014-05-11 09:57:58.154039 7fe9f87b6700  0 auth: could not find secret_id=2895
2014-05-11 09:57:58.154045 7fe9f87b6700  0 cephx: verify_authorizer could not get service secret for service mds secret_id=2895
2014-05-11 09:57:58.154048 7fe9f87b6700  0 -- 192.168.0.2:6800/25496 >> 192.168.0.7:0/2446 pipe(0x7fea05538000 sd=28 :6800 s=0 pgs=0 cs=0 l=0 c=0x7fea03f6b340).accept: got bad authorizer
2014-05-11 09:57:58.355668 7fe9f87b6700  0 -- 192.168.0.2:6800/25496 >> 192.168.0.7:0/2446 pipe(0x7fea3a94ec80 sd=28 :6800 s=0 pgs=0 cs=0 l=0 c=0x7fea04094580).accept connect_seq 2 vs existing 1 state standby
2014-05-11 09:57:58.759059 7fe9f87b6700  0 -- 192.168.0.2:6800/25496 >> 192.168.0.7:0/2446 pipe(0x7fea3a94e780 sd=21 :6800 s=0 pgs=0 cs=0 l=0 c=0x7fea040946e0).accept we reset (peer sent cseq 2), sending RESETSESSION
2014-05-11 13:32:00.837406 7fe9fc3c8700  0 mds.0.181 handle_mds_beacon no longer laggy
2014-05-11 18:03:13.986293 7fe9f9ac2700 -1 mds.0.181 *** got signal Terminated ***
2014-05-11 18:03:13.986323 7fe9f9ac2700  1 mds.0.181 suicide.  wanted down:dne, now up:active

At 18:03 I restarted active MDS and the next "standby" one took over:

2014-05-11 18:03:15.420060 7fdd0aa3d700  1 mds.0.0 replay_done (as standby)
2014-05-11 18:03:16.380048 7fdd0aa3d700  1 mds.0.182 handle_mds_map i am now mds.0.182
2014-05-11 18:03:16.380053 7fdd0aa3d700  1 mds.0.182 handle_mds_map state change up:standby-replay --> up:replay
2014-05-11 18:03:16.420142 7fdd08938700  1 mds.0.182 standby_replay_restart (as standby)
2014-05-11 18:03:16.422594 7fdd0aa3d700  1 mds.0.182 replay_done (as standby)
2014-05-11 18:03:16.422598 7fdd0aa3d700  1 mds.0.182 standby_replay_restart (final takeover pass)
2014-05-11 18:03:16.424686 7fdd0aa3d700  1 mds.0.182 replay_done
2014-05-11 18:03:16.424687 7fdd0aa3d700  1 mds.0.182 making mds journal writeable
2014-05-11 18:03:21.566836 7fdd0aa3d700  1 mds.0.182 handle_mds_map i am now mds.0.182
2014-05-11 18:03:21.566843 7fdd0aa3d700  1 mds.0.182 handle_mds_map state change up:replay --> up:reconnect
2014-05-11 18:03:21.566846 7fdd0aa3d700  1 mds.0.182 reconnect_start
2014-05-11 18:03:21.566848 7fdd0aa3d700  1 mds.0.182 reopen_log
2014-05-11 18:03:21.568912 7fdd0aa3d700  1 mds.0.server reconnect_clients -- 4 sessions
2014-05-11 18:03:21.588278 7fdd0aa3d700  0 log [DBG] : reconnect by new client.2919908 192.168.0.7:0/2446 after 0.018920
2014-05-11 18:03:21.604682 7fdd0aa3d700  0 log [DBG] : reconnect by client.2976796 192.168.0.250:0/19436 after 0.035745
2014-05-11 18:03:21.819712 7fdd0aa3d700  0 log [DBG] : reconnect by client.2927732 192.168.0.204:0/4206 after 0.250776
2014-05-11 18:03:22.407688 7fdd0aa3d700  0 log [DBG] : reconnect by client.2802672 192.168.0.2:0/12050 after 0.838754
2014-05-11 18:03:24.823116 7fdd0aa3d700  0 log [DBG] : reconnect by client.2788926 192.168.0.6:0/2428 after 3.254022
2014-05-11 18:03:25.095932 7fdd0aa3d700  1 mds.0.182 reconnect_done
2014-05-11 18:03:25.345916 7fdd0aa3d700  1 mds.0.182 handle_mds_map i am now mds.0.182
2014-05-11 18:03:25.345923 7fdd0aa3d700  1 mds.0.182 handle_mds_map state change up:reconnect --> up:rejoin
2014-05-11 18:03:25.345925 7fdd0aa3d700  1 mds.0.182 rejoin_start
2014-05-11 18:03:25.404962 7fdd0aa3d700  1 mds.0.182 rejoin_joint_start
2014-05-11 18:03:26.557855 7fdd0aa3d700  1 mds.0.182 rejoin_done
2014-05-11 18:03:27.805918 7fdd0aa3d700  1 mds.0.182 handle_mds_map i am now mds.0.182
2014-05-11 18:03:27.805924 7fdd0aa3d700  1 mds.0.182 handle_mds_map state change up:rejoin --> up:active
2014-05-11 18:03:27.805934 7fdd0aa3d700  1 mds.0.182 recovery_done -- successful recovery!
2014-05-11 18:03:28.435315 7fdd0aa3d700  1 mds.0.182 active_start
2014-05-11 18:03:28.435961 7fdd0aa3d700  1 mds.0.182 cluster recovered.

As you can see it managed to reconnect to fuse client at 192.168.0.7 where mount point started to respond again.

several other commits followed by commit 09a1bc5 are also required. These commits do not make fuse client recover automatically, still need to use admin socket to kick stale sessions. (This is because some metadata updates may get lost in this case. Actually 'restarting MDS makes the fuse client recover' is a bug, the MDS should not allow the client reconnect)

Dmitry Smirnov wrote:

Perhaps my initial confusion was because only the above-mentioned commit was cherry-picked to "firefly" branch.

Zheng could you be more specific please?
I applied commit:a0867dbdb0dfd014006b9852005bbada19973ed2 as merged from wip-client-sleep to 0.80 and easily reproduced the problem again.
We need to backport fix to Firefly. Are you sure this problem is fixed?

I used the following command to squash merge-commit into patch

The patch doesn't make ceph-fuse recover automatically. you need to use following command to recover hang fuse client

ceph --admin-daemon /var/run/ceph/ceph-fuse.asok kick_stale_sessions

In the context of wake up from suspend reconnecting to MDS should be safe as everything supposed to be flushed before suspend.
We should allow clients to reconnect to MDS on wake-up even if active MDS had changed during sleep.

It might be safe for the suspend/resume case. But the MDS can't distinguish it from other cases (such as someone freeze the ceph-fuse process).

A suspended client isn't participating in the cluster and gets booted out; if it has stale data it cannot rejoin the cluster safely and that isn't something we can resolve. For now I'd recommend unmounting before suspend.

I'm not very familiar with the kernel normally behaves around suspend, though — if it's flushing everything before actually going to sleep, we could perhaps have the client drop its caches and reconnect as a new client if it has no dirty buffers. Thoughts, Zheng?

Greg Farnum wrote:

A suspended client isn't participating in the cluster and gets booted out; if it has stale data it cannot rejoin the cluster safely and that isn't something we can resolve.

Kicking client who have file system mounted is very unsafe -- on wake up client can't even save other files to other file systems because UI hangs and application don't respond.
Reset (i.e. unclean shutdown) is hardly a safe action to recover from this situation.
Unexpectedly disconnected clients leave some files behind (e.g. libreoffice lock files etc.).

We should always allow client to rejoin even after long periods of inactivity.
That's what NFS do and perhaps other file systems as well.

Without knowing what application is doing it is not possible to decide whether it is "safe" or "unsafe" on server side.
If client falls behind after long period of inactivity let's make it reload its cache etc. but don't just kick it out like if it did something wrong.
Let's be user friendly and a bit more environment friendly by allowing resume from suspend. :)

For now I'd recommend unmounting before suspend.

What if my /home is on CephFS?
Even if user have enough rights to (un)mount can we seriously recommend to "close all files and unmount before suspend or risk losing all your work on resume"?

I'm not very familiar with the kernel normally behaves around suspend, though — if it's flushing everything before actually going to sleep, we could perhaps have the client drop its caches and reconnect as a new client if it has no dirty buffers.

This looks like a right thing to do.
Don't take my word on it but I think suspend procedure sync all file systems before changing power mode.
Actually whatever CepFS kernel client does it looks like correct behaviour.
At least with CepFS mounted using kernel client I was able to resume from short sleep successfully.
I'll try longer suspend to see how it work...

Zheng Yan wrote:

The attached (one line) patch can make fuse-client work as you expected.

Thanks, but I still can't make it work, sorry.
I applied your patch to v0.80.1 but on resume ceph-fuse did not respond, as usual.

It keeps logging the following to ceph-client.user.log:

2014-05-14 02:21:16.686178 7f79f08be700  0 -- 192.168.0.6:0/2046 submit_message client_session(request_renewcaps seq 142) v1 remote, 192.168.0.2:6802/20464, failed lossy con, dropping message 0x7f79cc00a250

Once again fuse client became operational only after restart of active MDS:

2014-05-14 02:28:13.682140 7f774155e700  0 log [DBG] : reconnect by new client.3216376 192.168.0.6:0/2046 after 0.023876

What is missing this time?

But you are at risk of losing dirty metadata unnoticeably.

That's OK. In the absence of journal, integrity can't be guaranteed without knowing what client is doing.