HBase Master启动报错java.io.IOException: error or interrupted while splitting logs

今天在一个CDH环境中启动HBase时HBase Master启动发生异常，HBase Master采用的是两台HMaster做一个HA。从CDH管理界面查询启动成功后，HBase Master状态并不太正常（如下图所示），

以上截图看似正常，实质不正常。正常情况下两个HMaster主备可用时，Master后面应该有一个标识是活动还是备份的状态，但上面图片中缺少状态信息。

于是查看两个HMaster日志，其中一台HBase Master日志信息正常，另外一台HBase Master日志一直在刷SplitLogManager相关的日志，过一会之后即有如下报错信息，

2020-06-20 20:00:54,345 WARN org.apache.hadoop.hbase.master.SplitLogManager: error while splitting logs in [hdfs://nameservice1/hbase/WALs/zfnode05.esgyn.cn,60020,1592556004866-splitting] installed = 1 but only 0 done
2020-06-20 20:00:54,345 WARN org.apache.hadoop.hbase.master.SplitLogManager: error while splitting logs in [hdfs://nameservice1/hbase/WALs/zfnode07.esgyn.cn,60020,1592556014755-splitting] installed = 1 but only 0 done
2020-06-20 20:00:54,346 WARN org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure: Failed serverName=zfnode05.esgyn.cn,60020,1592556004866, state=SERVER_CRASH_SPLIT_LOGS; retry
java.io.IOException: error or interrupted while splitting logs in [hdfs://nameservice1/hbase/WALs/zfnode05.esgyn.cn,60020,1592556004866-splitting] Task = installed = 1 done = 0 error = 0
        at org.apache.hadoop.hbase.master.SplitLogManager.splitLogDistributed(SplitLogManager.java:291)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:436)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:409)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:326)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.splitLogs(ServerCrashProcedure.java:449)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.executeFromState(ServerCrashProcedure.java:257)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.executeFromState(ServerCrashProcedure.java:75)
        at org.apache.hadoop.hbase.procedure2.StateMachineProcedure.execute(StateMachineProcedure.java:119)
        at org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:498)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1061)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExecutor.java:856)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExecutor.java:809)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureExecutor.java:75)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecutor.java:495)
2020-06-20 20:00:54,346 WARN org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure: Failed serverName=zfnode07.esgyn.cn,60020,1592556014755, state=SERVER_CRASH_SPLIT_LOGS; retry
java.io.IOException: error or interrupted while splitting logs in [hdfs://nameservice1/hbase/WALs/zfnode07.esgyn.cn,60020,1592556014755-splitting] Task = installed = 1 done = 0 error = 0
        at org.apache.hadoop.hbase.master.SplitLogManager.splitLogDistributed(SplitLogManager.java:291)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:436)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:409)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:326)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.splitLogs(ServerCrashProcedure.java:449)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.executeFromState(ServerCrashProcedure.java:257)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.executeFromState(ServerCrashProcedure.java:75)
        at org.apache.hadoop.hbase.procedure2.StateMachineProcedure.execute(StateMachineProcedure.java:119)
        at org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:498)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1061)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExecutor.java:856)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExecutor.java:809)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureExecutor.java:75)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecutor.java:495)
2020-06-20 20:00:54,355 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
2020-06-20 20:00:54,352 INFO org.apache.zookeeper.ZooKeeper: Session: 0x372d1899c99001f closed
2020-06-20 20:00:54,352 WARN org.apache.hadoop.hbase.master.SplitLogManager: Stopped while waiting for log splits to be completed
2020-06-20 20:00:54,360 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: stopping server zfnode02.esgyn.cn,60000,1592654144721; zookeeper connection closed.
2020-06-20 20:00:54,360 WARN org.apache.hadoop.hbase.master.SplitLogManager: error while splitting logs in [hdfs://nameservice1/hbase/WALs/zfnode08.esgyn.cn,60020,1592556004592-splitting] installed = 1 but only 0 done
2020-06-20 20:00:54,360 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: master/ZFnode02.esgyn.cn/10.19.41.22:60000 exiting
2020-06-20 20:00:54,361 WARN org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure: Failed serverName=zfnode08.esgyn.cn,60020,1592556004592, state=SERVER_CRASH_SPLIT_LOGS; retry
java.io.IOException: error or interrupted while splitting logs in [hdfs://nameservice1/hbase/WALs/zfnode08.esgyn.cn,60020,1592556004592-splitting] Task = installed = 1 done = 0 error = 0
        at org.apache.hadoop.hbase.master.SplitLogManager.splitLogDistributed(SplitLogManager.java:291)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:436)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:409)
        at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:326)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.splitLogs(ServerCrashProcedure.java:449)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.executeFromState(ServerCrashProcedure.java:257)
        at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.executeFromState(ServerCrashProcedure.java:75)
        at org.apache.hadoop.hbase.procedure2.StateMachineProcedure.execute(StateMachineProcedure.java:119)
        at org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:498)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1061)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExecutor.java:856)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExecutor.java:809)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureExecutor.java:75)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecutor.java:495)

再看RegionServer日志，报错信息如下，

2020-06-20 19:49:00,847 WARN org.apache.hadoop.hbase.coordination.ZkSplitLogWorkerCoordination: transisition task /hbase/splitWAL/WALs%2Fzfnode04.esgyn.cn%2C60020%2C1592556004686-splitting%2Fzfnode04.esgyn.cn%252C60020%252C1592556004686.null0.1592639729895 to RESIGNED zfnode03.esgyn.cn,60020,1592652946422 failed because of version mismatch
org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /hbase/splitWAL/WALs%2Fzfnode04.esgyn.cn%2C60020%2C1592556004686-splitting%2Fzfnode04.esgyn.cn%252C60020%252C1592556004686.null0.1592639729895
        at org.apache.zookeeper.KeeperException.create(KeeperException.java:115)
        at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
        at org.apache.zookeeper.ZooKeeper.setData(ZooKeeper.java:1266)
        at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.setData(RecoverableZooKeeper.java:422)
        at org.apache.hadoop.hbase.zookeeper.ZKUtil.setData(ZKUtil.java:818)
        at org.apache.hadoop.hbase.coordination.ZkSplitLogWorkerCoordination.endTask(ZkSplitLogWorkerCoordination.java:595)
        at org.apache.hadoop.hbase.regionserver.handler.WALSplitterHandler.process(WALSplitterHandler.java:96)
        at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:129)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

根据以下报错信息所指，问题出现hdfs://nameservice1/hbase/WALs/zfnode07.esgyn.cn,60020,1592556014755-splitting。

我们怀疑可能是上次HBase的split操作发生了异常，导致WAL目录下面仍然有splitting文件残留，我们使用以下命令删除这些异常的splitting文件，

hadoop fs -rmr /hbase/WALs/*-splitting

然后重启HBase Master，重启正常。