一、故障现象
- 两个节点的ResourceManger频繁在active和standby角色中切换。不断有active易主的告警发出
- 许多任务的状态没能成功更新,导致一些任务状态卡在NEW_SAVING无法进入调度(还有许多资源空闲)
看了下ResourceManger的日志,发现大量以下错误:
org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss
zk:java.io.IOException: Len error 2186401
二、问题分析
RM的HA机制分析
yarn.resourcemanager.zk-num-retries
配置,默认是1000次。当对应的zk操作失败重试达到1000次,RM就会将状态切换到standby。ZK问题分析
Exception causing close of session 0x16324e8243d0003 due to java.io.IOException: Len error 2186401
也很明确的表明是由于客户端发来的请求包太大,zk主动关闭了连接。上网搜了下zk的Len error
的问题,发现也有一些人碰到过。甚至找到两个相关的issue,一个是yarn的,一个是zookeeper的:
其中zk的issue是说如果一个请求要注册的watcher太多,会导致Len error的问题。因此这个issue的patch是将这些watcher分成多个请求发送,这样就不会导致请求过大的问题了。刚好修复版本是3.4.7,而我们集群用的zk版本是3.4.6。
yarn的issue是说之前的版本设置了过多无用的watcher,导致某个请求太大,出现Len error的问题。因此yarn这边做的修复是不在注册无用的watcher。修复版本是2.6.0,我们集群用的版本是2.7.4,因此我们集群应该不会有这个问题。
因为排查时已经无法找到那个请求包的具体内容,这两个issue看上去又很有说服力。虽然yarn已经修复了注册过多无用watcher的,但是可能还有一些地方还有类似的问题呢。
本来以为问题大概就是这样了,我们已经准备升级zk版本了。突然又想到失败的zk操作是updateApplicationAttemptStateInternal,它底层的zk操作是setData,而setData是不会注册任何watcher的。因此这个问题和watcher没有任何关系。
后面继续排查,发现下面这篇博客:
https://www.jishuwen.com/d/2BBc/zh-hk#tuit
和我们的故障现象很像,于是追到了博客提到的yarn的issue:
https://issues.apache.org/jira/browse/YARN-2368
ResourceManager failed when ZKRMStateStore tries to update znode data larger than 1MB
。也就是我们遇到的问题。就是要更新的任务信息过大导致的,和watcher没有关系。
这issue并没有修复的版本,看了下它的patch,就是加了一个配置,用来指定jute.maxbuffer
,也就是通过调大zk的阀值来避免出现该问题。
三、解决和优化方案
1. 调大 jute.maxbuffer 参数
通过调大jute.maxbuffer来让zk可以接受更大的请求包而不会抛出IOException。这个参数的默认值是1M。
注意,这个不是在zk的配置文件中设置。而是作为java参数在启动zk时设置,也就是-Djute.maxbuffer=xxxx的方式。
另外,根据zk的文档,这个参数在所有的客户端和zk服务端都要设置,否则会有更多的问题产生。也就是说,我们需要在yarn这边也设置这个参数。
这种方式有点治标不治本,因为我们无法知道任务信息最大可能到多少。设置过大的值也不是个好主意。最重要的是这个方案要同时对yarn和zk进行重启,风险略高。
2. 修改yarn的源码
byte[] attemptStateData = attemptStateDataPB.getProto().toByteArray();
//测试环境可以加上下面这个日志,实时观察各个任务信息的大小
LOG.info(String.format("attempId:%s,len:%s",attemptStateDataPB.getAttemptId(),attemptStateData.length));
//如果任务信息超过了950K,就打出error日志,输出任务信息,同时直接返回,不再往zk发送请求
if(attemptStateData.length > 972800){
LOG.error(String.format("attemptStateData len larger than 1M.len:%s,nodeUpdatePath:%s,data:%s,attemptId:%s,Diagnostics:%s,traceUrl:%s,container%s",
attemptStateData.length,nodeUpdatePath,String.valueOf(attemptStateData),attemptStateDataPB.getAttemptId(),attemptStateDataPB.getDiagnostics(),
attemptStateDataPB.getFinalTrackingUrl(),attemptStateDataPB.getMasterContainer()));
return;
}
//往zk发送请求更新任务信息
if (existsWithRetries(nodeUpdatePath, false) != null) {
setDataWithRetries(nodeUpdatePath, attemptStateData, -1);
} else {
createWithRetries(nodeUpdatePath, attemptStateData, zkAcl,
CreateMode.PERSISTENT);
LOG.debug(appAttemptId + " znode didn't exist. Created a new znode to"
+ " update the application attempt state.");
}