Ceph MDS Stuck in Client Replay 问题分析

最近一直在做 MDS 高可用方面的工作，发现 MDS （带 IO）重启时可能会长时间卡在 Client Replay 状态。这里对问题的原因做了一下分析，并给出了现有的以及未来的解决办法，希望能对大家有所帮助。

问题现象梳理

通过 ceph -s 看到 MDS 的状态长时间在 client replay 状态不变化：

1
2
3
4

[root@node2 ~]# ceph -s
    cluster:
    ...
    mds: cephfs: 1/1 {0=node2=up:clientreplay}

查看 MDS 状态会发现 clientreplay_queue 不为空，但是如果打开 MDS 日志会发现 MDS 什么都没做（除了心跳）：

1
2
3
4
5
6
7
8

ceph tell mds.ocs-storagecluster-cephfilesystem:0 status
{
  ...
    "clientreplay_status": {
        "clientreplay_queue": 125048,
        "active_replay": 0
    },
}

原因分析

那这里我们要分析这个问题，就要先知道 MDS 在 Client Replay 阶段做了什么。

首先我们知道 MDS 在启动过程中在 Replay 阶段完成以后（多 MDS 要在 Resolve 阶段以后）会进入 Reconnect 阶段，这个阶段顾名思义会等待客户端进行重连，这也是 MDS 在进入 Active 状态之前唯一能接收客户端请求的阶段，因此客户端会在这个阶段通过 Client::send_reconnect 向 MDS 发送 unsafe_requests, old_requests 以及 client_reconnect 消息, 其中 unsafe_requests 会通过 enqueue_replay 加入 replay_queue 中，old_requests 则会加入 waiting_for_active 等待 MDS 到 active 再处理，client_reconnect 消息则是客户端向 MDS 发送的最后一条消息表示客户端重连完成了（如果 MDS 没有收到这条消息就会把客户端 kill 掉）

1
2
3
4
5
6
7
8

void Server::dispatch(const cref_t<Message> &m)
{
  ...
    if (queue_replay) {
      req->mark_queued_for_replay();
      mds->enqueue_replay(new C_MDS_RetryMessage(mds, m));
      return;
    }

接着 MDS 到达 Client Replay 阶段之后就会从 replay_queue 中依次取出刚刚插入的消息并处理，如果一切正常的话每条消息都会在处理完成后 Server::journal_and_reply 或者 Server::reply_client_request 中通过 queue_one_replay 取出下一条消息并处理。

但问题在于并不是每一种情况 MDS 都能 cover 到，首先在任何情况下 Client 都有可能掉线，这导致 MDS 可能在任何时刻 kill_session （一个比较常见的情况是 ganesha 在 client_metadata 里设置了 timeout 所以没有在 Reconnect 阶段 kill_session）

那么如果处理消息时 client session 被 kill 掉又会发生什么呢，正常情况下在 Server::handle_client_request 中如果发现这个 session 被 kill 了那么会 queue_one_replay 处理下一个消息：

1
2
3
4
5
6
7

void Server::handle_client_request(const cref_t<MClientRequest> &req)
{
  if (!session) {
    if (req->is_queued_for_replay())
      mds->queue_one_replay();
    return;
  }

但是如果这个消息此时不是刚开始处理的话就会遇到问题了，假设此前处理请求时候,需要拿锁 Server::acquire_locks：

1

2022-03-15 12:22:40.185171 7f3e57e90700 10 mds.0.locker wrlock_start (inest sync dirty) on ...

这里拿 wrlock 想要把 inest 锁从 sync 状态转成 lock 状态，但是因为此时 inest 锁状态是 dirty 的，因此需要通过 scatter_writebehind 刷一把 journal，并 WAIT_STABLE:

1
2
3
4
5
6
7
8
9

bool Locker::wrlock_start(const MutationImpl::LockOp &op, MDRequestRef& mut)
{
  ...
  dout(7) << "wrlock_start waiting on " << *lock << " on " << *lock->get_parent() << dendl;
  lock->add_waiter(SimpleLock::WAIT_STABLE, new C_MDS_RetryRequest(mdcache, mut));
  nudge_log(lock);

  return false;
}

这里注意 add_waiter 设置的回调是 C_MDS_RetryRequest 和之前加入 replay_queue 时的 C_MDS_RetryMessage 是不一样的，这里就是问题的关键。

当 scatter_writebehind 完成之后由 scatter_writebehind_finish 调到 C_MDS_RetryRequest::finish

1
2
3
4
5

void C_MDS_RetryRequest::finish(int r)
{
  mdr->retry++;
  cache->dispatch_request(mdr);
}

这里直接进入了 MDCache::dispatch_request:

1
2
3
4

void MDCache::dispatch_request(MDRequestRef& mdr)
{
  if (mdr->client_request) {
    mds->server->dispatch_client_request(mdr);

可以看到这里没有走 Server::handle_client_request 而是直接进入了 Server::dispatch_client_request，在这里对于已经被 kill 掉的 session 的处理就有一个 corner case:

1
2
3
4
5
6
7
8
9
10

void Server::dispatch_client_request(MDRequestRef& mdr)
{
  // we shouldn't be waiting on anyone.
  ceph_assert(!mdr->has_more() || mdr->more()->waiting_on_peer.empty());

  if (mdr->killed) {
    dout(10) << "request " << *mdr << " was killed" << dendl;
    return;
  }
  ...

这里可以看到直接 return 掉了而没有进行 queue_one_replay，这就使得 MDS 没有办法继续往下进行了

除了这种情况以外在 MDCache::request_start 失败时也会直接返回而不会有机会 queue_one_replay

如何解决

目前遇到这种情况没有其他办法，只能通过重启 MDS 来解决（因为没有机会触发 queue_one_replay）

社区的相关进展

这个问题实际上社区很早就发现了， queue_one_replay 这个改动就是 YanZheng 在 6352f181 为了 fix ‘stuck in clientreplay’ 的问题提的，但是实际上就像我上面分析的还有一些 corner case 没有覆盖到，这就导致在一些场景下我们仍会遇到这样的问题。

最新的话是 Patrick 在 #47121 中提了一个改动想统一一下 queue_one_replay 的位置，正好我前两天分析了这一块所以给 Patrick 说了现有的这些可能导致 MDS 卡住的情况，然后后面我会再看一下他提的这个 PR 能不能解决问题，如果可以的话后面合到主线应该就不会出现这种问题了。