Running ceph tell mds.a drop cache displays output from MDSRank::command_flush_journal() as well as from MDSRank::cache_status().

{
    "message": "",
    "return_code": 0
}
{
    "pool": {
        "items": 482,
        "bytes": 52398
    }
}

Do we want both or only the latter?

both, combine into one object

should be:

{
    "message": "",
    "return_code": 0
    "cache_status": {
      "pool": {
          "items": 482,
          "bytes": 52398
      }
  }
}

Okay. From a general user's POV, I think it will be difficult to understand the context of the first two lines. Perhaps it'll be better to add a section with title "flush_journal" like the following snippet?

{
    "flush_journal": {
        "message": "",
        "return_code": 0
    },
    "cache": {
        "pool": {
            "items": 482,
            "bytes": 52398
        }
    }
}

Updating the PR with "flush_journal" part included. Let me know if you think it's not good idea.

@batrick I don't know if this change is really appropriate but without it the MDS crashes after the executing the command at this line [1] since it expects MDS to be locked.

[1] https://github.com/ceph/ceph/blob/master/src/mds/MDSDaemon.cc#L1143

I'd suggest moving Mutex::Locker l(mds_lock) to surround the call to _command_flush_journal in command_flush_journal:

to be

{
  Mutex::Locker l(mds_lock);
  const int r = _command_flush_journal(&ss);
}

Then comment MDSrank::_command_flush_journal that it expects mds_lock to be locked.

I think we can keep this vague. Don't mention dropping cache. Also, rename to mds_session_recall_ack_timeout.

add Mutex::Locker l(mds_lock);

@batrick Using Mutex::Locker l(mds_lock); creates the same issue as before [1]. At least for time being, I am replacing it by mds_lock.Lock() so that MDS would stay locked until control reaches here [2] after exiting command_drop_cache(); this prevents MDS from crashing.

[1] #21566 (comment)
[2] https://github.com/ceph/ceph/blob/master/src/mds/MDSDaemon.cc#L1143

Oh, right that lock is not necessary because it's locked in MDSDaemon::ms_dispatch.

should call _command_flush_journal.

Use:

std::unique_ptr<Formatter> fmtr(new JSONFormatter(true));

then

fmtr.reset(new JSONFormatter(true));

when you want to create a new one.

As I noted elsewhere, what you should actually do is concatenate all of the commands outputs into one JSON object. So you should be using the same JSONFormatter for all of these commands. Just create a new object section before calling each command.

This needs to be using waiter/gather continuations. @ukernel can you suggest the right approach.

see code in Server::flush_client_sessions() and see how does it get used

I originally wrote this code to make MDS consume less CPU. Should it be gotten rid of? I am confused since discussion of waiter/gather continuations began from here.

I don't see how 'sleep' consume less CPU. please get rid of it.

Done.

I was under the impression that sleep would lead to lesser number of iterations (when ACKs are not received spontaneously) allowing other threads/processes to use that CPU time instead.

The right way to do this is to record a sequence number for the recall messages the MDS sends so that the client can ACK the seq number. Then we know which recall messages it has handled. Recall what Zheng said in the email thread: "we can add a recall_state seq to MClientCapRelease and MClientSession message.".

Please modify those messages (and increment the message version) to include the sequence number.

Please correct me if I am wrong: in my understanding, I need to assign seq. numbers to CEPH_SESSION_RECALL_STATE messages being sent by MDS in Server::client_recall_state, store them for later and then while receiving ACKs (until mds_session_recall_ack_timeout) for these messages I need to check them and report the ones (in the logs) I haven't received an ACK for.

Recall what Zheng said in the email thread: "we can add a recall_state seq to MClientCapRelease and MClientSession message.".

Yeah, I couldn't comprehend the "seq" part back then.

Updating the PR as per my understanding above.

This should actually be a pair of sequence numbers (version_t) that are associated with each session (just like seq numbers in TCP). The first would be what the MDS sends and sequentially increases with each new CEPH_SESSION_RECALL_STATE message. The second would be what the client sends back as finished, via the CEPH_SESSION_RECALL_STATEMSG_ACK message.

But now that I'm reading the code more in SessionMap.h, I'm wondering if we can reuse the existing CEPH_SESSION_FLUSHMSG code for this purpose. There is already a sequence number in the session to use (see the code for Session::cap_push_seq. @ukernel would this be appropriate or should we use a separate sequence number?

using Session::cap_push_seq is appropriate.

If client always sends ACK immediately after receiving drop cache request, existing Session::{wait_for_flush,finish_flush} code can serve this purpose completely. If not, need introduce a new waiter list ( similar to Session::waitfor_flush)

@batrick

This should actually be a pair of sequence numbers (version_t) that are associated with each session (just like seq numbers in TCP). The first would be what the MDS sends and sequentially increases with each new CEPH_SESSION_RECALL_STATE message. The second would be what the client sends back as finished, via the CEPH_SESSION_RECALL_STATEMSG_ACK message.

If sequence number of the message sent by MDS is different from that of the client, I wouldn't know which sessions have not been trimmed and it will not be possible to report those sessions in the log. Though I can still see how many sessions have not trimmed. Will that be okay?

check code that handle CEPH_SESSION_FLUSHMSG/CEPH_SESSION_FLUSHMSG_ACK. they use the same seq number. please reuse cap_push_seq instead of introducing a new one

@ukernel Done. Thanks. :)

Does client always send ACK immediately

@ukernel Client will always send ACKs but I don't if its fast enough to be immediate as it calls trim_caps() first.

Recalling from one of the reply Patrick's on the mail, clients that have caps pinned locally will not return the cap. In that case ACK may not be returned.

I think trimming the cache should occur after we get all the client recall acks. We want to trim the MDS cache when the client caps are released.

can be fmtr->open_object_section...

The MDS should do a wait, not an infinite loop. You need to add a waiter interface for this.

The MDS should do a wait, not an infinite loop.

It's not infinite. The looping stops on timeout.

Sorry my wording was wrong. It's not infinite but it is a busy-wait. i.e. the CPU loops until the condition is true... for TIMEOUT seconds. This isn't acceptable.

Got it.

this needs to go at the end of the enum otherwise the binary compatibility of the state messages is compromised

recall_acked = m->get_seq()

why static?

I saw MDS crash without it -

(gdb)
1155      set<Session*> sessions;
(gdb)
1133      MDSGatherBuilder gather(g_ceph_context);
(gdb)

Program received signal SIGABRT, Aborted.
0x00007f7fd283b277 in __GI_raise (sig=sig@entry=6)
    at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56        return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
(gdb)
handle_fatal_signal (signum=6)
    at /home/centos/repos/ceph/src/global/signal_handler.cc:92
92      {
(gdb) c
Continuing.

I do not have a higher understanding of how MDS runs as a daemon but I saw the line being executed multiple times. So, the making it static seemed like a natural solution.

Why did you move this var?

Moved it during re-writings. Undid this change.

pass a pointer to

MDSGatherBuilder gather(g_ceph_context);

to server->recall_client_state which adds to the gather:

https://github.com/ceph/ceph/pull/21566/files#diff-eecf840e09d7481f7b8f415789852c7dR1177

then you can do a gather.activate() in _wait_for_client_recall_state_acks instead of the cpu-intensive loop.

@batrick I can't figure out how to replace the busy/wait loop by gather.activate(). Also, calling gather.activate() in _wait_for_client_recall_state_acks leads to a crash due to the assert in gather.activate() [1]

And would these changes mean no need timeout? If so, the option mds_session_recall_ack_timeout will be redundant.

[1] https://github.com/ceph/ceph/blob/master/src/include/Context.h#L476

typo "ratio"

I don't see how this will work (ceph tell). The dispatcher is processing this MCommand message here. I believe it will remain blocked on command_cache_drop until the timeout is reached. During this time, the MDS should not be able to process the messages from the clients. (Unless the messenger dispatch thread count is bumped I guess, I've not tried this recently.)

I think it will be necessary to convert this drop cache command into an asynchronous Context which releases the dispatch thread back to the messenger. Consider that this is a problem we share with asynchronous scrub which currently executes in an unaccountable way in the MDS. It'd be valuable to have a generic "command" module of some kind which allows the operator to manipulate/stop these operations once started.

This doesn't need to be written now but it's worth thinking about. I think we can solve drop cache by just using contexts to drive the drop to completion and eventually send an MCommandReply once finished. The dispatch thread should be released ASAP. If it simplifies the code, go ahead and drop the asok version.

batrick wrote

I don't see how this will work (ceph tell). The dispatcher is processing this MCommand message here. I believe it will remain blocked on command_cache_drop until the timeout is reached. During this time, the MDS should not be able to process the messages from the clients. (Unless the messenger dispatch thread count is bumped I guess, I've not tried this recently.)

It indeed does not -

$ date && ./bin/ceph tell mds.a cache drop 20 && date
Fri Sep  7 10:22:51 UTC 2018
{
    "client_recall": {
        "return_code": 0,
        "message": "(0) Success"
    },
    "flush_journal": {
        "return_code": 0,
        "message": ""
    },
    "cache": {
        "pool": {
            "items": 583,
            "bytes": 57080
        }
    }
}
Fri Sep  7 10:22:51 UTC 2018

... unlike using the asok command -

$ date && ./bin/ceph daemon mds.a cache drop 20 && date
Fri Sep  7 10:19:38 UTC 2018
{
    "client_recall": {
        "return_code": 0,
        "message": "(0) Success"
    },
    "flush_journal": {
        "return_code": 0,
        "message": ""
    },
    "cache": {
        "pool": {
            "items": 729,
            "bytes": 67320
        }
    }
}
Fri Sep  7 10:19:38 UTC 2018

The tell command waits until timeout only when session->caps.size() > newlim[1] -

$ date && ./bin/ceph tell mds.a cache drop 20 && date
Fri Sep  7 10:23:16 UTC 2018
{
    "client_recall": {
        "return_code": 0,
        "message": "(0) Success"
    },
    "flush_journal": {
        "return_code": 0,
        "message": ""
    },
    "cache": {
        "pool": {
            "items": 583,
            "bytes": 57080
        }
    }
}
Fri Sep  7 10:23:17 UTC 2018

For that mds min caps per client needs to be set (in ceph.conf) to some lower value (depending on FS).

Thanks @batrick -- I understand the issue with ceph tell now. With @rishabh-d-dave testing above, I expected client_recall status to return ETIMEDOUT.

Its probably worth to drive command_cache_drop() via context. I'll look into this and update the PR.

start would be better I think

that's what I got used to when writing async state machines in rbd ;)

Let's inherit from MDSInternalContext so it hooks into some general purpose logging too.

makes sense