Ceph MDS Behind On Trimming Error

January 26, 2018
Author:Eric
Source:http://blog.wjin.org/posts/ceph-mds-behind-on-trimming-error.html
Declaration: this work is licensed under a Creative Commons Attribution-NonCommercial 4.0 International License. Creative Commons License

Introduction

在CephFS集群运行过程中,如果一直持续不停的写入大量文件,会报告Warning信息:mds Behind on trimming…。从文档查看,这个错误是因为日志(MDLog)没来得急trim导致的。一直持续写入文件的时候,虽然data和metadata共用osd,但是优化后的osd负载并不高,trim操作不会因为后端集群负载而delay。告警信息本身影响不大,但是为什么不能及时trim值得深入研究。

Trim Process

为了一探究竟,需要深入了解mds trim log的流程。首先明确CephFS mds进程管理日志的相关类。MDLog集中管理日志,跟踪所有的LogSegment,包含当前active的segment和expiring/expired的segment。当一个segment的使用量达到上限(比如超过segment所规定的事件个数),就新起一个segment,segment数量会逐渐增加,需要定期做trim操作。LogSegment记录一连串的LogEvent事件(这里事件有很多种,对文件系统的更新操作都属于某种事件)。另外,MDLog中包含一个对象Journaler,用来向rados写日志/事件。

触发trim操作的入口函数是时间tick函数:

void MDSDaemon::tick()
{
	tick_event = 0;

	reset_tick(); // 每隔mds_tick_interval秒,调用tick一次,默认值为5秒

	if (mds_rank) {
		mds_rank->tick();
	}
}

void MDSRankDispatcher::tick()
{
	......
	if (is_active() || is_stopping()) {
		......
		mdlog->trim();
	}
	......
}

void MDLog::trim(int m) // 函数默认参数-1
{
	// 获取配置参数
	unsigned max_segments = g_conf->mds_log_max_segments;
	int max_events = g_conf->mds_log_max_events; // 默认为-1
	if (m >= 0)
		max_events = m;

	if (mds->mdcache->is_readonly()) { // 只读,直接返回
		return;
	}

	// 调整max_events,通常情况下,仍然为-1
	if (max_events > 0 && max_events <= g_conf->mds_log_events_per_segment) {
		max_events = g_conf->mds_log_events_per_segment + 1;
	}

	submit_mutex.Lock();

	if (segments.empty()) { // segment为空,不需要trim,直接返回
		submit_mutex.Unlock();
		return;
	}

	// 设置trim的最长时间,每次2秒钟
	utime_t stop = ceph_clock_now(g_ceph_context);
	stop += 2.0;

	// 遍历segment,event或segment的条件满足其一即做trim
	map<uint64_t,LogSegment*>::iterator p = segments.begin();
	while (p != segments.end() &&
			((max_events >= 0 && num_events - expiring_events - expired_events > max_events) ||
			(segments.size() - expiring_segments.size() - expired_segments.size() > max_segments))) {

		if (stop < ceph_clock_now(g_ceph_context)) // 超出时间,退出循环
			break;

		int num_expiring_segments = (int)expiring_segments.size();
		if (num_expiring_segments >= g_conf->mds_log_max_expiring) // 超出并发trim的限制,退出循环
			break;

		// 计算op的优先级,后续执行try_to_expire的时候,可能会有执行rados op的操作,这个就是rados op的优先级
		// 如果expiring的segment比较多,优先级就越高
		int op_prio = CEPH_MSG_PRIO_LOW +
			(CEPH_MSG_PRIO_HIGH - CEPH_MSG_PRIO_LOW) *
			num_expiring_segments / g_conf->mds_log_max_expiring;

		LogSegment *ls = p->second;
		assert(ls);
		++p;

		// 如果LogSegment包含有pending事件,或者还不能做trim(日志还没落盘),退出循环
		// 注意LogSegment的seq是log event中的序列号,event的序列号单调递增,全局唯一
		// 新建segment的时候,用当前event的序列号作为segment的序列号
		if (pending_events.count(ls->seq) || ls->end > safe_pos) {
			break;
		}

		// 已经在expiring或expired中,不做任何操作
		if (expiring_segments.count(ls)) {
		} else if (expired_segments.count(ls)) {
		} else { // 否则,将LogSegment加入expiring
			assert(expiring_segments.count(ls) == 0);
			expiring_segments.insert(ls);
			expiring_events += ls->num_events;
			submit_mutex.Unlock();

			uint64_t last_seq = ls->seq;
			try_expire(ls, op_prio); // 尝试expire

			submit_mutex.Lock();
			p = segments.lower_bound(last_seq + 1); // 更新循环迭代器
		}
	}

	// 将expired的segment删除,并更新journaler的expire位置,这个位置也很重要,mds发生异常的时候,此位置即为日志回放的起点
	_trim_expired_segments();
}

try_expire调用try_to_expire判断一个LogSegment能否最终被trim,实现非常复杂。LogSegment中包含多个链表以及集合,比如dirty dir/inode/dentry以及和目录分片相关的信息。try_to_expire依次循环遍历这些链表和集合,如果不能做trim,就创建callback放入GatherBuild中,GatherBuild搜集所有callback,记录callback的上下文,即产生一个链式callback。

void MDLog::try_expire(LogSegment *ls, int op_prio)
{
  MDSGatherBuilder gather_bld(g_ceph_context); // callback集中处理
  ls->try_to_expire(mds, gather_bld, op_prio); // 判断LogSegment是否能够执行expired

  if (gather_bld.has_subs()) { // 如果gather包含callback事件,暂时不能执行expired操作,等待下次继续调用
    gather_bld.set_finisher(new C_MaybeExpiredSegment(this, ls, op_prio));
    gather_bld.activate();
  } else { // 可以执行
    submit_mutex.Lock();
    expiring_segments.erase(ls);
    expiring_events -= ls->num_events;
    _expired(ls); // 将LogSegment放入expired集合
    submit_mutex.Unlock();
  }
  
  logger->set(l_mdl_segexg, expiring_segments.size());
  logger->set(l_mdl_evexg, expiring_events);
}

总结一下,整个流程大致是将需要做trim的segment先放入expring中的集合,然后执行try_expire进行判断是否能够trim,并将其放入expired集合,最后调用_trim_expirted_segments清理expired集合。

Config

主要配置参数如下:

mds_log_max_events // 默认值为-1,即没有上限
mds_log_events_per_segment // 每个segment包含事件数的上限,默认为1024。超过上限,新起一个segment
mds_log_segment_size // 每个segment的大小,默认值为0,采用object的大小,即4 mb
mds_log_max_segments // 最大的segment,默认值为30。另一层含义是: 当segment的个数超过此值的两倍,就会发生文章开头的告警信息
mds_log_max_expiring // 能同时做expiring的segment个数,默认值为20

Tuning

如果要避免告警信息,可以从两个方面考虑:

  1. 减少segment的个数

  2. 增加trim的速度

对于第一点,可以调整segment的size和事件个数的上限。注意两者要同时调整,很多事件包含成员EMetaBlob,这个类包含成员还比较多,对象大小应该不小,默认的事件个数1024应该是根据默认对象大小4mb和事件平均大小估算的一个合理值。

对于第二点,首先trim函数每隔5秒钟调用一次,这个参数不应该调整,tick函数不只是做trim操作,还有其他逻辑。每次最多执行两秒中,这个写死在代码里,也不应该去改代码,因为涉及到submit_mutex,不应该频繁的去抢占这个锁。

剩下就是对参数mds_log_max_segments和mds_log_max_expiring的调整,前者不应该调整的太大,太大的话虽然暂时避免了告警信息,但是一直持续写入,最终还是会告警,而且太大存在的LogSegment就太多,异常情况下mds回放日志就会耗费太长时间。最后剩下的参数mds_log_max_expiring,可以根据自己集群的规模和硬件,在不影响客户端IO的情况下适当调大。

异常情况下的恢复流程如下,可以看见回放日志的起点是expire结束的时候:

// 初始化回放日志的起点的流程:
MDLog::_recovery_thread() -> Journaler::recover() -> Journaler::_read_head() -> Journaler::_finish_read_head()

read_pos = requested_pos = received_pos = expire_pos = h.expire_pos; // journaler head的expire位置

同时将mds_log_max_segment调整的比较大的时候,比如1000,观察到cephfs的元数据池使用量增加非常明显,大部分是日志的增加,文件系统本身的元数据只有几百MB:

GLOBAL:
SIZE      AVAIL     RAW USED     %RAW USED
1455T     1118T         336T         23.15
POOLS:
NAME                ID     USED      %USED     MAX AVAIL     OBJECTS
cephfs_metadata     1      5759M         0          301T     10128861
cephfs_data         2       112T     27.10          301T     57787299

鉴于此,生产环境不建议调整mds_log_max_segments。从实际观察看,参数mds_log_max_expiring很容易达到上限,导致trim不及时,容易发生告警信息,发现社区已经对此问题做了优化,参见patch,可以将此patch backport回来。另外如果不想修改代码,参数mds_log_max_expiring调整多大不好判断,可以直接放任它不管,但是在监控告警层面,即从命令Ceph Health的结果中过滤告警信息,然后在metric系统中监控segment的相关指标,并在metric系统中对segment的阈值进行告警,这个阈值可以设置的比较大,只是以防代码有bug导致segment变的非常大,比如几百万(通常情况下,持续写入几百万的文件,segment的最大值观察到在1万左右)。

下面是一些可以监控的metric指标:

 "mds_log": {
        # active/expiring/expired的event个数
        "ev": {
            "type": 2,
            "description": "Events",
            "nick": "evts"
        },
        "evexg": {
            "type": 2,
            "description": "Expiring events",
            "nick": ""
        },
        "evexd": {
            "type": 2,
            "description": "Current expired events",
            "nick": ""
        },

        # active/expiring/expired的segment个数
        "seg": {
            "type": 2,
            "description": "Segments",
            "nick": "segs"
        },
        "segexg": {
            "type": 2,
            "description": "Expiring segments",
            "nick": ""
        },
        "segexd": {
            "type": 2,
            "description": "Current expired segments",
            "nick": ""
        },

        # journal 过期/写/读的位置
        "expos": {
            "type": 2,
            "description": "Journaler xpire position",
            "nick": ""
        },
        "wrpos": {
            "type": 2,
            "description": "Journaler  write position",
            "nick": ""
        },
       "rdpos": {
            "type": 2,
            "description": "Journaler  read position",
            "nick": ""
        },
    }

Summary