L版本闲置Ceph集群 BlueFS Log容量异常增长的问题分析

【问题描述】
L版本 12.2.13
空置一年的集群，检查发现大量OSD的meta容量占用特别高；
重启这些OSD，会长时间卡在BlueFS::_replay()函数里；
这些OSD最终有的可以启动，有的会因为Log的校验报错而停止启动；
replay时间以小时计，盘越大的时间越长。
独立DB分区的OSD从未出现过Log容量无限增长的问题，而未单独配置block.db的OSD则很大概率出此问题

最后无奈只能删除OSD重建，但是集群空置一段时间后，这个现象又回来了。

从BlueStore.cc中的kv提交线程开始分析：

void BlueStore::_kv_sync_thread()
{
  dout(10) << __func__ << " start" << dendl;
  std::unique_lock<std::mutex> l(kv_lock);
  assert(!kv_sync_started);
  bool bluefs_do_check_balance = false;
  kv_sync_started = true; 
  kv_cond.notify_all();
  while (true) {
    assert(kv_committing.empty());
    if (kv_queue.empty() &&
        ((deferred_done_queue.empty() && deferred_stable_queue.empty()) ||
         !deferred_aggressive) &&
        (bluefs_do_check_balance == false)) {

闲置的时候，上面所有queue都空，bluefs_do_check_balance初始为false，进入到
if流程，在等待默认1秒没有新的kv写时，bluefs_do_check_balance被置为true

      if (kv_stop)
        break;
      dout(20) << __func__ << " sleep" << dendl;
      std::cv_status status = kv_cond.wait_for(l,
        std::chrono::milliseconds(int64_t(cct->_conf->bluestore_bluefs_balance_interval * 1000)));
      dout(20) << __func__ << " wake" << dendl;
      if (status == std::cv_status::timeout) {
        bluefs_do_check_balance = true; 
      }     
    } else {

下一次循环时，由于bluefs_do_check_balance被置为true，进入到else流程，省略掉很多无关代码，以...代替

    } else {
      deque<TransContext*> kv_submitting;
      deque<DeferredBatch*> deferred_done, deferred_stable;
      uint64_t aios = 0, costs = 0;
      ... ...
      // we will use one final transaction to force a sync
      KeyValueDB::Transaction synct = db->get_transaction();

上面这行代码挺关键，用意是获取db记录的最后一个transaction，后面用它来触发一次sync操作，确保本次循环所commit的事务落盘。
大致的流程如下：

... ...
      for (auto txc : kv_committing) {
        if (txc->state == TransContext::STATE_KV_QUEUED) {
          txc->log_state_latency(logger, l_bluestore_state_kv_queued_lat);
          int r = cct->_conf->bluestore_debug_omit_kv_commit ? 0 : db->submit_transaction(txc->t);
          assert(r == 0);
          txc->state = TransContext::STATE_KV_SUBMITTED;
          ... ...

        } else {
          assert(txc->state == TransContext::STATE_KV_SUBMITTED);
          txc->log_state_latency(logger, l_bluestore_state_kv_queued_lat);
        }
        ... ...
      }
      ... ...
      PExtentVector bluefs_gift_extents;
      if (bluefs &&
          after_flush - bluefs_last_balance >
          cct->_conf->bluestore_bluefs_balance_interval) {
        bluefs_last_balance = after_flush;
        int r = _balance_bluefs_freespace(&bluefs_gift_extents);
        assert(r >= 0);
        if (r > 0) {
          for (auto& p : bluefs_gift_extents) {
            bluefs_extents.insert(p.offset, p.length);
          }
          bufferlist bl;
          ::encode(bluefs_extents, bl);
          dout(10) << __func__ << " bluefs_extents now 0x" << std::hex
                   << bluefs_extents << std::dec << dendl;
          synct->set(PREFIX_SUPER, "bluefs_extents", bl);
        }
      }
      ... ...，

上面的流程大致为：对kv_committing队列里的事务，调用db->submit_transaction提交，而后进行bluefs的空闲空间判断，空闲空间过大时执行回收空间并更新bluefs_extents记录；更新后的bluefs_extents记录序列化后，附加到此前获得的synct事务中，期望伴随着synct事务一起提交并sync，接下来

// submit synct synchronously (block and wait for it to commit)
int r = cct->_conf->bluestore_debug_omit_kv_commit ? 0 : db->submit_transaction_sync(synct);
assert(r == 0);

这里调用了db->submit_transaction_sync ，注意前面提交业务Io时，用的db->submit_transaction提交，两个函数有什么不同，等会儿分析。

回顾上面的流程，在集群空闲没有业务IO时，周期性的过程：

  1. KeyValueDB::Transaction synct = db->get_transaction(); // 一定被执行
  2. db->submit_transaction(txc->t); // 一定不执行，因为没有新的事务进来
  3. _balance_bluefs_freespace(&bluefs_gift_extents); // 周期性执行
  4. synct->set(PREFIX_SUPER, "bluefs_extents", bl); // 低频率执行，因为后面synct的提交可能逐渐撑大bluefs空间，而Log compaction又释放掉空间导致bluefs free比例过大，引发第三步的空间回收过程。
  5. db->submit_transaction_sync(synct); // 一定会执行

从上面的过程可以初步划定范围，导致BlueFS容量无限增长的可能触发点在这两个位置：

  1. _balance_bluefs_freespace(&bluefs_gift_extents);
  2. db->submit_transaction_sync(synct);

当出现问题时，OSD重启时会在BlueFS::_replay(bool noop)函数中长时间循环，可以推断，出问题的OSD，有巨量的BlueFS Log在做回放

先对_balance_bluefs_freespace做分析，函数中有可能操作硬盘的调用为：
bluefs->reclaim_blocks(bluefs_shared_bdev, reclaim, &extents);
这里的bluefs_shared_bdev，在有单独DB设备时，它是BDEV_DB，否则是BDEV_SLOW

int BlueFS::reclaim_blocks(unsigned id, uint64_t want,
                           PExtentVector *extents)
{
  std::unique_lock<std::mutex> l(lock);
  dout(1) << __func__ << " bdev " << id
          << " want 0x" << std::hex << want << std::dec << dendl;
  assert(id < alloc.size());
  assert(alloc[id]);

  int64_t got = alloc[id]->allocate(want, alloc_size[id], 0, extents);
  ceph_assert(got != 0);
  if (got < 0) {
    derr << __func__ << " failed to allocate space to return to bluestore"
      << dendl;
    alloc[id]->dump();
    return got;
  }

  for (auto& p : *extents) {
    block_all[id].erase(p.offset, p.length);
    block_total[id] -= p.length;
    log_t.op_alloc_rm(id, p.offset, p.length);
  }

  flush_bdev();
  int r = _flush_and_sync_log(l);
  assert(r == 0);

  if (logger)
    logger->inc(l_bluefs_reclaim_bytes, got);
  dout(1) << __func__ << " bdev " << id << " want 0x" << std::hex << want
          << " got " << *extents << dendl;
  return 0;
}

上面的函数，传入的extents大概率是空的。所以log_t并未被更新
紧接着调用了 _flush_and_sync_log函数，看看里面做了什么

int BlueFS::_flush_and_sync_log(std::unique_lock<std::mutex>& l,
                                uint64_t want_seq,
                                uint64_t jump_to)
{
  while (log_flushing) {
    dout(10) << __func__ << " want_seq " << want_seq
             << " log is currently flushing, waiting" << dendl;
    assert(!jump_to);
    log_cond.wait(l);
  }
  if (want_seq && want_seq <= log_seq_stable) {
    dout(10) << __func__ << " want_seq " << want_seq << " <= log_seq_stable "
             << log_seq_stable << ", done" << dendl;
    assert(!jump_to);
    return 0;
  }
  if (log_t.empty() && dirty_files.empty()) {
    dout(10) << __func__ << " want_seq " << want_seq
             << " " << log_t << " not dirty, dirty_files empty, no-op" << dendl;
    assert(!jump_to);
    return 0;
  }

 ... ...

dirty_files是空的，到这里log_t.empty()应该成立，所以函数返回了，什么也没做。

至此
3. _balance_bluefs_freespace(&bluefs_gift_extents);导致Log无限增长的原因排除了。
只剩下最后一个嫌疑点：
5. db->submit_transaction_sync(synct);

调用链

问题出在BlueFS::sync_metadata()函数里面

1413fed24c791654a5d6a7e31ab03de.png

经过前面的分析，log_t大概率就是empty的，所以，上面的if条件导致下面的if没有执行机会，也就没能触发log compaction
社区有修复的PR，包含在在12.2.14版本
https://github.com/ceph/ceph/pull/34876

不免会有新的疑问：总有非empty的log来触发这个compaction吧？
追踪调用链，在rocksdb的DBImpl实现里面，只有两种情况会触发BlueRocksDirectory::Fsync()

  • 首次收到woptions.sync == true的写请求的时候
  • 切换到新的memtable时

假如这两种情况触发时，写下去的事务都是空的呢？
就很可能出现BlueRocksDirectory::Fsync()被调用，但log_t里面啥也没有的情况，
下面这个PR虽没有被社区接受，原因是end of life，但我相信它确实堵住了源头
https://github.com/ceph/ceph/pull/36108

综上，问题已经比较明晰

  1. 在集群无业务负载时，周期性db->submit_transaction_sync调用，提交空的事务
  2. 在首次提交以及切换memtable时，触发BlueRocksDirectory::Fsync()，但由于log_t为空，未能执行log compact
  3. 第1、2经年累月的反复执行，导致WAL File的log不断增长，又得不到compaction处理，日志空间不断增大。
  4. 当日志增大到极限大小，约500GB时，会出现日志损坏的情况(具体原因还不明)
  5. 此时，OSD重启时，就会经历漫长的replay过程，而且最终因日志损坏而失败，OSD无法启动。

解决方案
我认为，仅仅是我认为，将如下两个PR一起使用，能够解决问题：

  1. 让compact log总是有机会执行： https://github.com/ceph/ceph/pull/34876
  2. 尽可能的避免提交空事务： https://github.com/ceph/ceph/pull/36108
最后编辑于 ：
©著作权归作者所有,转载或内容合作请联系作者
平台声明：文章内容（如有图片或视频亦包括在内）由作者上传并发布，文章内容仅代表作者本人观点，简书系信息发布平台，仅提供信息存储服务。

推荐阅读更多精彩内容