场景
NameNode迁移,导致一个节点无法启动
异常
在Namenode主动迁移,或者Namenode机器挂掉无法恢复时,我们需要Namenode节点迁移,迁移经常会出现一个NameNode启动成功,另外一个standby启动失败,报错如下
2019-09-27 15:19:23,818 WARN org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Encountered exception loading fsimage
java.io.IOException: There appears to be a gap in the edit log. We expected txid 266899638, but got txid 267088002.at org.apache.hadoop.hdfs.server.namenode.MetaRecoveryContext.editLogLoaderPrompt(MetaRecoveryContext.java:94)at org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.loadEditRecords(FSEditLogLoader.java:230)at org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.loadFSEdits(FSEditLogLoader.java:158)at org.apache.hadoop.hdfs.server.namenode.FSImage.loadEdits(FSImage.java:882)at org.apache.hadoop.hdfs.server.namenode.FSImage.loadFSImage(FSImage.java:739)at org.apache.hadoop.hdfs.server.namenode.FSImage.recoverTransitionRead(FSImage.java:317)at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.loadFSImage(FSNamesystem.java:1112)at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.loadFromDisk(FSNamesystem.java:738)at org.apache.hadoop.hdfs.server.namenode.NameNode.loadNamesystem(NameNode.java:665)at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:727)at org.apache.hadoop.hdfs.server.namenode.NameNode.<init>(NameNode.java:950)at org.apache.hadoop.hdfs.server.namenode.NameNode.<init>(NameNode.java:929)at org.apache.hadoop.hdfs.server.namenode.NameNode.createNameNode(NameNode.java:1653)at org.apache.hadoop.hdfs.server.namenode.NameNode.main(NameNode.java:1720)
2019-09-27 15:19:23,832 INFO org.eclipse.jetty.server.handler.ContextHandler: Stopped o.e.j.w.WebAppContext@4c398c80{/,null,UNAVAILABLE}{/hdfs}
2019-09-27 15:19:23,838 INFO org.eclipse.jetty.server.AbstractConnector: Stopped ServerConnector@75390459{HTTP/1.1,[http/1.1]}{fwqml009.zh:9870}
2019-09-27 15:19:23,838 INFO org.eclipse.jetty.server.handler.ContextHandler: Stopped o.e.j.s.ServletContextHandler@4983159f{/static,file:///opt/cloudera/parcels/CDH-6.0.0-1.cdh6.0.0.p0.537114/lib/hadoop-hdfs/webapps/static/,UNAVAILABLE}
2019-09-27 15:19:23,839 INFO org.eclipse.jetty.server.handler.ContextHandler: Stopped o.e.j.s.ServletContextHandler@753432a2{/logs,file:///var/log/hadoop-hdfs/,UNAVAILABLE}
2019-09-27 15:19:23,840 INFO org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Stopping NameNode metrics system...
2019-09-27 15:19:23,841 INFO org.apache.hadoop.metrics2.impl.MetricsSystemImpl: NameNode metrics system stopped.
2019-09-27 15:19:23,842 INFO org.apache.hadoop.metrics2.impl.MetricsSystemImpl: NameNode metrics system shutdown complete.
2019-09-27 15:19:23,842 ERROR org.apache.hadoop.hdfs.server.namenode.NameNode: Failed to start namenode.
java.io.IOException: There appears to be a gap in the edit log. We expected txid 266899638, but got txid 267088002.at org.apache.hadoop.hdfs.server.namenode.MetaRecoveryContext.editLogLoaderPrompt(MetaRecoveryContext.java:94)at org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.loadEditRecords(FSEditLogLoader.java:230)at org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader.loadFSEdits(FSEditLogLoader.java:158)at org.apache.hadoop.hdfs.server.namenode.FSImage.loadEdits(FSImage.java:882)at org.apache.hadoop.hdfs.server.namenode.FSImage.loadFSImage(FSImage.java:739)at org.apache.hadoop.hdfs.server.namenode.FSImage.recoverTransitionRead(FSImage.java:317)at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.loadFSImage(FSNamesystem.java:1112)at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.loadFromDisk(FSNamesystem.java:738)at org.apache.hadoop.hdfs.server.namenode.NameNode.loadNamesystem(NameNode.java:665)at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:727)at org.apache.hadoop.hdfs.server.namenode.NameNode.<init>(NameNode.java:950)at org.apache.hadoop.hdfs.server.namenode.NameNode.<init>(NameNode.java:929)at org.apache.hadoop.hdfs.server.namenode.NameNode.createNameNode(NameNode.java:1653)at org.apache.hadoop.hdfs.server.namenode.NameNode.main(NameNode.java:1720)
2019-09-27 15:19:23,844 INFO org.apache.hadoop.util.ExitUtil: Exiting with status 1: java.io.IOException: There appears to be a gap in the edit log. We expected txid 266899638, but got txid 267088002.
在网上一搜上面异常,基本都是
hadoop namenode -recover
或者让我格式化NameNode...(线上数据不能这么玩~)
我的场景使用 -recover 会报错,:(
原因分析
原因是 standby Namenode启动会去 jn (JournalNode,Namenode HA场景下,是通过JournalNode进行过数据同步)获取数据,但是jn 没有,具体查看一下
上面日志提示 We expected txid 266899638, but got txid 267088002. 也就是Namenode想要获取266899638这个edit,但是获取到的是267088002,查看 jn 目录下,发现的确只有267088002 即:edits_0000000000267088002-0000000000267088002
[root@jast009 current]# ll
总用量 480380
-rw-r--r-- 1 hdfs hdfs 8 9月 27 15:23 committed-txid
-rw-r--r-- 1 hdfs hdfs 2506691 9月 26 15:58 committed-txid.bak
-rw-r--r-- 1 hdfs hdfs 25 9月 26 10:30 edits_0000000000267088002-0000000000267088002
-rw-r--r-- 1 hdfs hdfs 755 9月 26 10:37 edits_0000000000267088003-0000000000267088010
-rw-r--r-- 1 hdfs hdfs 756 9月 26 10:39 edits_0000000000267088011-0000000000267088018
-rw-r--r-- 1 hdfs hdfs 1471 9月 26 10:41 edits_0000000000267088019-0000000000267088032
-rw-r--r-- 1 hdfs hdfs 756 9月 26 10:43 edits_0000000000267088033-0000000000267088040
-rw-r--r-- 1 hdfs hdfs 1470 9月 26 10:45 edits_0000000000267088041-0000000000267088054
-rw-r--r-- 1 hdfs hdfs 1472 9月 26 10:47 edits_0000000000267088055-0000000000267088068
-rw-r--r-- 1 hdfs hdfs 1048576 9月 26 10:47 edits_0000000000267088069-0000000000267088069
-rw-r--r-- 1 hdfs hdfs 12401 9月 26 10:52 edits_0000000000267088070-0000000000267088170
-rw-r--r-- 1 hdfs hdfs 2580282 9月 26 10:54 edits_0000000000267088171-0000000000267104853
-rw-r--r-- 1 hdfs hdfs 309195 9月 26 10:56 edits_0000000000267104854-0000000000267106831
-rw-r--r-- 1 hdfs hdfs 264231 9月 26 10:58 edits_0000000000267106832-0000000000267108442
-rw-r--r-- 1 hdfs hdfs 915772 9月 26 11:00 edits_0000000000267108443-0000000000267114308
-rw-r--r-- 1 hdfs hdfs 727526 9月 26 11:02 edits_0000000000267114309-0000000000267118780
-rw-r--r-- 1 hdfs hdfs 3411288 9月 26 11:04 edits_0000000000267118781-0000000000267139507
-rw-r--r-- 1 hdfs hdfs 1048576 9月 26 11:04 edits_0000000000267139508-0000000000267139508
-rw-r--r-- 1 hdfs hdfs 17352 9月 26 11:10 edits_0000000000267139509-0000000000267139673
-rw-r--r-- 1 hdfs hdfs 1282451 9月 26 11:12 edits_0000000000267139674-0000000000267146671
-rw-r--r-- 1 hdfs hdfs 2714992 9月 26 11:14 edits_0000000000267146672-0000000000267164211
-rw-r--r-- 1 hdfs hdfs 340434 9月 26 11:17 edits_0000000000267164212-0000000000267166258
-rw-r--r-- 1 hdfs hdfs 335975 9月 26 11:19 edits_0000000000267166259-0000000000267168268
-rw-r--r-- 1 hdfs hdfs 423730 9月 26 11:21 edits_0000000000267168269-0000000000267171145
-rw-r--r-- 1 hdfs hdfs 1048576 9月 26 15:29 edits_0000000000267171146-0000000000267174696
-rw-r--r-- 1 hdfs hdfs 757 9月 26 15:34 edits_0000000000267233868-0000000000267233875
-rw-r--r-- 1 hdfs hdfs 1048576 9月 26 15:55 edits_0000000000267233876-0000000000267233972
-rw-r--r-- 1 hdfs hdfs 22020096 9月 27 10:53 edits_0000000000267233973-0000000000267396690
-rw-r--r-- 1 hdfs hdfs 382730240 9月 27 15:23 edits_inprogress_0000000000267396691
-rw-r--r-- 1 hdfs hdfs 3 9月 27 11:00 last-promised-epoch
-rw-r--r-- 1 hdfs hdfs 3 9月 27 11:00 last-writer-epoch
drwxr-xr-x 2 hdfs hdfs 6 9月 27 11:00 paxos
-rw-r--r-- 1 hdfs hdfs 136 9月 26 10:30 VERSION
我们尝试将需要的数据copy到jn 目录下,并重启,看看是否可以恢复。
我们去NameNode目录下(两个NameNode节点目录都看一下)将所有edits_0xxxx文件全部复制到 jn节点保存目录
这里复制过程省略....... scp即可,看自己心情
文件复制完成后,需要重启 JN 节点(JN 都停了的话Namenode也需要停),是使新导入数据生效
启动Namenode,发现成功
查看日志,万事大吉,一切正常工作