HDFS使用Ambari切主遇到的坑

现象：
今天部署机架感知，重启standby节点，然后切主生效。在切主的时候使用ambari的 restart zkfc，导致切主不成功并且原standby nn节点挂掉。慌的一匹，问了领导再重启一次就好了，顺便给我讲了一下原理。本着对问题刨根问底的精神，我挖了挖源码，来看看这个问题产生的原因。

首先总结一下导致这个现象的基本原因： restart zkfc的过程很快，大概只有5秒。当Active NN上面的zkfc停掉的时候，被standby NN上的zkfc检测到。于是ZKFC开始准备让standby NN变成Active NN。但是由于这中间需要tail editlog，加载editlog等等耗时的工作，所以肯定是大于5秒的。然后ANN上面的ZKFC重启成功了，检测到对方的状态有问题，又将自己变成ANN。然后当SNN准备变成ANN时，发现自己的epoch小于当前最新的epoch，无法写editlog到journal node，于是抛异常挂掉。

从源码的角度分析

• 准备工作：

收集Namenode挂掉时候的日志：发现有如下内容：

Remote journal [ip地址] failed to write txns 3098267305-3098267305. Will try to write to this JN again after the next log roll.

org.apache.hadoop.ipc.RemoteException(java.io.IOException): IPC's epoch 25 is less than the last promised epoch 26 ; journal id: [集群名]
        at org.apache.hadoop.hdfs.qjournal.server.Journal.checkRequest(Journal.java:463)
        at org.apache.hadoop.hdfs.qjournal.server.Journal.checkWriteRequest(Journal.java:489)
        at org.apache.hadoop.hdfs.qjournal.server.Journal.journal(Journal.java:374)
        at org.apache.hadoop.hdfs.qjournal.server.JournalNodeRpcServer.journal(JournalNodeRpcServer.java:189)
        at org.apache.hadoop.hdfs.qjournal.protocolPB.QJournalProtocolServerSideTranslatorPB.journal(QJournalProtocolServerSideTranslatorPB.java:162)
        at org.apache.hadoop.hdfs.qjournal.protocol.QJournalProtocolProtos$QJournalProtocolService$2.callBlockingMethod(QJournalProtocolProtos.java:27401)
        at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:524)
        at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1025)
        at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:876)
        at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:822)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:422)
        at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1730)
        at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2682)

        at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1497)
        at org.apache.hadoop.ipc.Client.call(Client.java:1443)
        at org.apache.hadoop.ipc.Client.call(Client.java:1353)
        at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:228)
        at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:116)
        at com.sun.proxy.$Proxy12.journal(Unknown Source)
        at org.apache.hadoop.hdfs.qjournal.protocolPB.QJournalProtocolTranslatorPB.journal(QJournalProtocolTranslatorPB.java:187)
        at org.apache.hadoop.hdfs.qjournal.client.IPCLoggerChannel$7.call(IPCLoggerChannel.java:396)
        at org.apache.hadoop.hdfs.qjournal.client.IPCLoggerChannel$7.call(IPCLoggerChannel.java:389)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

根据log去源码中搜索相关线索，找到如下源码信息：

reqInfo.getEpoch() 此处是25，lastPromisedEpoch此处是26。
看注释抛出的异常，很容易知道，是往journal node上写editlog时出错了。

那我们就得看看lastPromisedEpoch是在什么条件下会被赋值，顺着set方法找，发现这个对象里面的long值存在于一个磁盘上的文件。当journal node第一次被加载或者之后的任何format操作都会从磁盘上重新加载这个文件。经过追踪调用树，发现如下代码会最终让journal node加载这个值。

好的，搞明白lastPromisedEpoch是什么时候加载的之后，我们看看，lastPromisedEpoch是什么时候更新的吧。

QuorumJournalManager类下面有个createNewUniqueEpoch，就是更新lastPromisedEpoch的值的。通过方法调用树，我们最终找到transitionToActive方法会调用createNewUniqueEpoch。

也就是说，在切主时，会调用createNewUniqueEpoch方法，增加lastPromises的值。

那也就好解释了，由于SNN切主没成功，原ANN先是transitionToStandby。然后再transitionToActive。这样lastPromisedEpoch又+1。然后SNN在状态变为Active的那短暂时间往journal node写edit log失败，遂挂掉。

Notes

反思一下：切主不能restart zkfc，要用stop zkfc，然后观察状态，切成功之后再启动刚才关闭的ZKFC。