Application运行失败导致RM主备切换

先说故障现象:
某天收到RM主备切换报警,正常切换并不会有什么影响,但我当时还是出于警觉想去服务器上check下为什么切,check的时候发现集群无法提交任务,所以的任务都被挂起了。
第一反应是原standby节点有问题,于是手动又触发了一次切换,但任务依然无法运行。主备RM都重启过了但问题依然无法解决,那只能使用终极杀手锏了,重启了整个yarn集群。
集群重启之后任务恢复了,心里舒了一口气,去查RM的log吧,看下是什么原因导致了这次故障,log还没有细看,只看到一些KeeperErrorCode = ConnectionLoss,此时悲剧发生了,又收到了RM切换的报警,任务又被挂起了。。。

毫无头绪,只能再次重启集群,这次重点关注了下集群上运行任务,估计是哪个任务把集群给干瘫了,观察到有个任务运行失败的时候集群就会被瘫,看了下该任务的报错信息特别特别的长,于是告诉任务的负责人暂时把任务停掉,观察下集群是不是因为这个任务导致的。

该任务停掉之后集群正常运行了一段时间,在这段时间内在查RM的log并没有发现太多有价值的东西,全是与zk的连接丢失,连接丢失确实是会触发主备切换,但关键是为什么连接会丢失呢?没有头绪,只好去zk server端看下log,发现报2018-11-27 15:54:30,208 [myid:1] - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@373] - Exception causing close of session 0x36753e378030000 due to java.io.IOException: Len error 8603591

对这个error进行了搜索之后,有人说是zk的一个bug,在某个版本中已经修复,而我用的这个版本我看了下代码也已经修复了,后来手里有其它事再忙,就又另一个同事跟这个故障,调整了个zk的参数jute.maxbuffer搞定,这个参数控制着写入node的数据量。

整个故障的原因是app在失败的时候会写入一些信息到zk,这些信息超过了zk的默认配置,导致写失败,链接就丢失了,主备就切换了,切换成功之后依然再尝试去写,总是写失败,所以整个集群就被卡住了。

Root Cause

这次并没有什么关键字可以让我们迅速找到关键代码处,此时你对源码的熟悉程度就能帮你迅速的定位了,这也就是为什么我们要熟悉源码的原因。

我们先来梳理下整个故障的全流程,流程如下:
故障流程

是不是有点Application状态机的样子,那我们就从这里入手。

Application状态是从RUNNING状态又事件ATTEMPT_FAILED触发,将状态进行改变的,看下对应状态转化的处理类AttemptFailedTransition
transition方法中找到关键方法rememberTargetTransitionsAndStoreState,看下代码:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
private void rememberTargetTransitionsAndStoreState(RMAppEvent event,
Object transitionToDo, RMAppState targetFinalState,
RMAppState stateToBeStored) {
...
String diags = null;
switch (event.getType()) {
case APP_REJECTED:
case ATTEMPT_FINISHED:
case ATTEMPT_KILLED:
diags = event.getDiagnosticMsg();
break;
case ATTEMPT_FAILED:
RMAppFailedAttemptEvent failedEvent = (RMAppFailedAttemptEvent) event;
diags = getAppAttemptFailedDiagnostics(failedEvent);
break;
default:
break;
}
// add by sunzhiwei for zk jute.maxbuffer
if (diags.length() > zkMaxBuffer) {
diags = diags.substring(0, zkMaxBuffer);
LOG.warn("The diags is too long, so it needs to be intercepted : " + diags);
}
ApplicationStateData appState =
ApplicationStateData.newInstance(this.submitTime, this.startTime,
this.user, this.submissionContext,
stateToBeStored, diags, this.storedFinishTime);
this.rmContext.getStateStore().updateApplicationState(appState);
}

这里把diags进行封装,通过updateApplicationState将app相关的信息写入zk中。(与写入zk相关的代码在ZKRMStateStore.updateApplicationStateInternal中)

知道了原因就好办了,我在这里将diags的长度进行了截取,并将其截取的长度进行了可配置化。
之所以这么改是因为我们不能一味的调整zk的jute.maxbuffer参数,这始终是个雷,我们应该从根处解决问题。

目前此代码已提交给社区,jira地址是YARN-9065

但是提交到社区之后,相关人员反馈了另一个patch,他修复的方式比我的方法优雅,感觉自己还是太简单粗暴了,嘿嘿。。。贴下jira地址可以参考下YARN-6125

您的肯定,是我装逼的最大的动力!