Hadoop运维笔记 之 Namenode异常停止后无法正常启动

2016-07-12 10:21:24来源:oschina作者:dannyhe人点击

Hadoop运维笔记 之 Namenode异常停止后无法正常启动:

存储,学习,共享。。。。


公司在线上使用了CDH5 HA模式,有两个Namenode节点,结果其中的Standby节点因为一些关于edits文件的报错异常停止了,并且在启动的过程中一直报告找不到各种文件。


刚开始怀疑问题可能只发生在Standby本身,因此尝试了bootstrapStandby来重新初始化Standby节点,但问题依旧。而后来因为我 尝试重启ZKFC(Zookeeper Failover)服务器,导致了Active节点进行自动切换,在切换失败后打算切换回去时,也无法启动服务了,报错跟Standby节点一模一样,于 是整个Hadoop集群就挂了。


问题严重,在搜遍了整个Google都找不到任何有用的信息之后,只能求助于老大。最后,老大想到一个思路,就是将fsimage(元数据)文件与edits(编辑日志)文件都反编译成文本,查看里面具体有什么内容,为什么加载edits文件时会报错。


结果,这个思路给我们带来了曙光,并最终修复了整个集群。


环境介绍:


idc2-server1: namenode, journalnode, zkfc


idc2-server2: namenode, journalnode, zkfc


idc2-server3: journalnode, resourcemanager


具体过程:


首先,是Standby Namenode上出现以下错误,然后自动异常关闭了进程:


2014-11-1102:12:54,057FATALorg.apache.hadoop.hdfs.server.namenode.ha.EditLogTailer:Unknownerrorencounteredwhiletailingedits.ShuttingdownstandbyNN.
java.io.FileNotFoundException:Filedoesnotexist:/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000015_0/part-00015
atorg.apache.hadoop.hdfs.server.namenode.INodeFile.valueOf(INodeFile.java:65)
atorg.apache.hadoop.hdfs.server.namenode.INodeFile.valueOf(INodeFile.java:55)
...

其中提到了"Unknown error encountered while tailing edits. Shutting down standby NN."


于是,我们尝试启动Standby Namenode服务,结果报告以下错误:


2014-11-1204:26:28,860INFOorg.apache.hadoop.hdfs.server.namenode.EditLogInputStream:Fast-forwardingstream'http://idc2-server10.heylinux.com:8480/getJournal?jid=idc2&segmentTxId=240823073&storageInfo=-55%3A1838233660%3A0%3ACID-d77ea84b-1b24-4bc2-ad27-7d2384d222d6'totransactionID2407412562014-11-1204:26:28,874ERRORorg.apache.hadoop.hdfs.server.namenode.FSEditLogLoader:EncounteredexceptiononoperationCloseOp[length=0,inodeId=0,path=/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000015_0/part-00015,replication=3,mtime=1415671845582,atime=1415670522749,blockSize=134217728,blocks=[],permissions=oozie:hdfs:rw-r--r--,aclEntries=null,clientName=,clientMachine=,opCode=OP_CLOSE,txid=240823292]
java.io.FileNotFoundException:Filedoesnotexist:/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000015_0/part-00015atorg.apache.hadoop.hdfs.server.namenode.INodeFile.valueOf(INodeFile.java:65)atorg.apache.hadoop.hdfs.server.namenode.INodeFile.valueOf(INodeFile.java:55)
...2014-11-1204:26:32,641WARNorg.apache.hadoop.hdfs.server.namenode.FSNamesystem:Encounteredexceptionloadingfsimage
java.io.FileNotFoundException:Filedoesnotexist:/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000015_0/part-00015atorg.apache.hadoop.hdfs.server.namenode.INodeFile.valueOf(INodeFile.java:65)

说找不到"/user/dong/data/dpp/classification/gender/vw-output-train /2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary /attempt_1415171013961_37060_m_000015_0/part-00015"这个文件。


而事实上,这个文件是临时文件,不重要并且已经被删除了。


但在上面,却报告"ERROR org.apache.hadoop.hdfs.server.namenode.FSEditLogLoader: Encountered exception on operation CloseOp",可以看出是在加载edits文件,执行OP_CLOSE操作时提示找不到文件。


刚开始我们怀疑可能只是Standby上的fsimage文件或edits文件有问题,于是我们在Standby上执行了 bootstrapStandby,改过程会自动从Active Namenode上获取最新的fsimage文件,并从Journalnode日志服务器上下载并执行新的edits文件。


sudo-uhdfshadoopnamenode-bootstrapStandby

但是,在初始化之后,加载edits时仍然遇到上面相同的报错。


而接下来,由于我尝试将ZKFC(Zookeeper Failover)服务重启,导致了Active Namenode自动切换到Standby,但由于Standby无法take over,所以Active Namenode切换回去的时候,也无法正常重启了,错误跟Standby启动时一样。


这样一来,整个Hadoop集群就挂了,在搜遍了整个Google都找不到任何有用的信息之后,我打电话给了老大,老大也通过上面的错误Google不到任何一条有用的信息。于是老大尝试在edits文件中grep上面的路径,找到了一些相关的edits文件:


#cd/data1/dfs/nn/#cp-rpacurrentcurrent.backup.orig#cd/data2/dfs/nn/#cp-rpacurrentcurrent.backup.orig#cd/data1/dfs/nn/current#grepattempt_1415171013961_37060_m_000015_0*Binaryfileedits_0000000000240687057-0000000000240698453matches
Binaryfileedits_0000000000240823073-0000000000240838096matches
Binaryfileedits_inprogress_0000000000244853266matches

于是,我们思考能否从这些edits文件或fsimage文件中找到一些线索。


而下面的两篇文章中,提到了Hadoop自带的针对fsimage和edits文件的反编译工具:


http://hadoop.apache.org/docs/current/hadoop-project-dist/hadoop-hdfs/HdfsImageViewer.html


http://hadoop.apache.org/docs/current/hadoop-project-dist/hadoop-hdfs/HdfsEditsViewer.html


其中,关于edits文件的一些描述给我们带来了极大的希望:


Incasethereissomeproblemwithhadoopclusterandtheeditsfileiscorrupteditispossibletosaveatleastpartoftheeditsfilethatiscorrect.ThiscanbedonebyconvertingthebinaryeditstoXML,edititmanuallyandthenconvertitbacktobinary.

通过以上描述,我们了解到edits文件可能会corrupted,而反编译之后手动修改,在编译回二进制格式进行替换,可以作为一种解决办法。于是我们将上面找到的两个关联edits文件,将其复制出来并进行了反编译:


mkdir/tmp2/
cd/data1/dfs/nn
cpedits_0000000000240687057-0000000000240698453/tmp2/
cpedits_0000000000240823073-0000000000240838096/tmp2/
hdfsoev-iedits_0000000000240687057-0000000000240698453-oedits_0000000000240687057-0000000000240698453.xml
hdfsoev-iedits_0000000000240823073-0000000000240838096-oedits_0000000000240823073-0000000000240838096.xml

反编译之后,生成了两个XML文件,我们在XML文件中搜索"/user/dong/data/dpp/classification/gender /vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun /_temporary/1/_temporary/attempt_1415171013961_37060_m_000015_0/part- 00015",找到了OP_CLOSE与OP_DELETE相关记录:



OP_DELETE

240818498
0
/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000015_0/part-00015
1415671972595
4a38861d-3bee-40e6-abb6-d2b58f313781
676



OP_CLOSE

240823292
0
0
/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000015_0/part-00015
3
1415671845582
1415670522749
134217728



oozie
hdfs
420



可以看到,对于"/user/dong/data/dpp/classification/gender/vw-output-train /2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary /attempt_1415171013961_37060_m_000015_0/part-00015",OP_DELETE发生在了 OP_CLOSE之前,因此执行OP_CLOSE时会提示"File does not exist"。


于是,我们尝试将OP_CLOSE这部分代码,替换成其它的内容,比如无关痛痒的修改一个现有文件的权限,并保留TXID 240823292以确保edits文件的完整性。



OP_SET_PERMISSIONS

240823292
/user/oozie-heylinux/.staging/job_1415171013961_37194
504


修改完成之后,再将XML文件反编译回binary格式。


cd/tmp2/
cpedits_0000000000240823073-0000000000240838096.xmledits_0000000000240823073-0000000000240838096.xml.orig
vimedits_0000000000240823073-0000000000240838096.xml
hdfsoev-iedits_0000000000240823073-0000000000240838096.xml-oedits_0000000000240823073-0000000000240838096-pbinary

然后将binary文件同步到journalnode日志服务器中:


cd/var/hadoop/data/dfs/jn/idc2prod/
cp-rpacurrentcurrent.backup.1cd/tmp2/
cpedits_0000000000240823073-0000000000240838096/data1/dfs/nn/current/
cpedits_0000000000240823073-0000000000240838096/data2/dfs/nn/current/
cpedits_0000000000240823073-0000000000240838096/var/hadoop/data/dfs/jn/idc2prod/current/
scpedits_0000000000240823073-0000000000240838096root@idc2-server2:/var/hadoop/data/dfs/jn/idc2prod/current/
scpedits_0000000000240823073-0000000000240838096root@idc2-server3:/var/hadoop/data/dfs/jn/idc2prod/current/

然后启动namenode服务,可以发现,之间的错误已经不存在了,取而代之的已经变成了其它文件。


2014-11-1208:57:13,053INFOorg.apache.hadoop.hdfs.server.namenode.EditLogInputStream:Fast-forwardingstream'http://idc2-server1.heylinux.com:8480/getJournal?jid=idc2prod&segmentTxId=240823073&storageInfo=-55%3A1838233660%3A0%3ACID-d77ea84b-1b24-4bc2-ad27-7d2384d222d6'totransactionID2402992102014-11-1208:57:13,063ERRORorg.apache.hadoop.hdfs.server.namenode.FSEditLogLoader:EncounteredexceptiononoperationCloseOp[length=0,inodeId=0,path=/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000018_0/part-00018,replication=3,mtime=1415671845675,atime=1415670519537,blockSize=134217728,blocks=[],permissions=oozie:hdfs:rw-r--r--,aclEntries=null,clientName=,clientMachine=,opCode=OP_CLOSE,txid=240823337]
java.io.FileNotFoundException:Filedoesnotexist:/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000018_0/part-00018atorg.apache.hadoop.hdfs.server.namenode.INodeFile.valueOf(INodeFile.java:65)atorg.apache.hadoop.hdfs.server.namenode.INodeFile.valueOf(INodeFile.java:55)
...2014-11-1208:57:16,847WARNorg.apache.hadoop.hdfs.server.namenode.FSNamesystem:Encounteredexceptionloadingfsimage
java.io.FileNotFoundException:Filedoesnotexist:/user/dong/data/dpp/classification/gender/vw-output-train/2014-10-30-research-with-confict-fix-bug-rerun/_temporary/1/_temporary/attempt_1415171013961_37060_m_000018_0/part-00018atorg.apache.hadoop.hdfs.server.namenode.INodeFile.valueOf(INodeFile.java:65)
...

那么,接下来,就是重复以上动作,其中有时候能找到一部分规律,可以批量将同一个目录下反复报错的文件的OP_CLOSE都替换掉。但更多的时候则是随机 的文件,需要一次次修改XML文件,然后编译成binary,再启动namenode,进行针对性的修改,一直反复的进行下去,直到Namenode能够 成功启动为止。


我们在具体的操作过程中,还遇到过关于OP_ADD_BLOCK的错误,造成问题的原因是由于最后一个edits文件在反编译回binary文件时出现一些关于OP_UPDATE_BLOCK的错误。


我将报错的部分通过以上方式进行了替换,才成功的将edits文件反编译回binary文件。


具体的解决办法,就是根据"Encountered exception on operation AddBlockOp"定位到OP_ADD_BLOCK相关配置并替换即可。


2014-11-1218:07:39,070ERRORorg.apache.hadoop.hdfs.server.namenode.FSEditLogLoader:EncounteredexceptiononoperationAddBlockOp[path=/user/dong/data/dpp/classification/gender/vw-input/2014-10-30-research-with-no-confict-fix-bug-rerun/all_labelled/_temporary/1/_temporary/attempt_1415171013961_42350_m_001474_0/part-m-01474,penultimateBlock=NULL,lastBlock=blk_1109647729_35920089,RpcClientId=,RpcCallId=-2]
java.lang.IllegalStateException

最后,在Namenode启动成功后,会报告很多Block丢失,解决办法是通过fsck删除这些错误的Block。


hadoopfsck/-files-blocks-locations|tee-afsck.out

然后在fsck.out中获取所有Block的信息,执行"hadoop fsck / -move"加Block进行删除。


最后,退出safemode,生活再次变得美好起来。


hadoopdfsadmin-safemodeleave"

Hadoop,Namenode

最新文章

123

最新摄影

微信扫一扫

第七城市微信公众平台