hadoop重启Namenode时,appTokens报FileNotFoundException
现象 报错如下 Application application_1405852606905_0014 failed 3 times due to AM Container for appattempt_1405852606905_0014_000003 exited with exitCode: -1000 due to: RemoteTrace: java.io.FileNotFoundException: File does not exist: hdfs:
现象
报错如下
Application application_1405852606905_0014 failed 3 times due to AM Container for appattempt_1405852606905_0014_000003 exited with exitCode: -1000 due to: RemoteTrace: java.io.FileNotFoundException: File does not exist: hdfs://mycluster:8020/user/kpi/.staging/job_1405852606905_0014/appTokens at org.apache.hadoop.hdfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:809)
同时注意到是因为每次重启nodemanager才发生。
首先用关键词“apptokens FileNotFoundException”在google和issue搜索没找到相关的问题。
猜测原因
可能找不到的原因:1.客户端没上传成功 2.上传成功了,但后面不知道给谁删了
重现
既然在网上找不到,尝试在测试环境重现这个问题,运行一个sleep job
cd /opt/cloudera/parcels/CDH/lib/hadoop-mapreduce; hadoop jar hadoop-mapreduce-client-*-tests.jar sleep -Dmapred.job.queue.name=sleep -m5 -r5 -mt 60000 -rt 30000 -recordt 1000
重启nodemanage后会发现报错。
分析日志
但发现找不到AM的日志,哪里去了?我们的hadoop环境都配置了“日志聚集”(yarn.log-aggregation-enable),失败的任务就把日志删了(可能是bug),尝试关掉后,从crontainer日志找到AM日志。
同时还可以看ResourceManager,NameNode,HDFS审计日志(hdfs-audit.log)
从AM日志可以看到第一次尝试好像是成功的,从HDFS审计日志发现了删除staging的目录
cmd=delete src="http://fatkun.com/user/kpi/.staging/job_1405852606905_0013">
到此可以确认目录是被删除了,导致后面的job失败,但谁删了这个目录?
继续搜索
代码很多,需要定位一下那里操作.staging这个目录,确定谁删了这个目录。在issue搜索“staging delete”,看有没有相关的操作代码。 同时阅读代码发现了org.apache.hadoop.mapreduce.v2.app.MRAppMaster.cleanupStagingDir()方法,对照日志,可以确定是这个方法删除了staging目录。
public synchronized void stop() { ... //这里判断了是不是AM的最后一次尝试,如果是才清理 if(isLastAMRetry) { cleanupStagingDir(); } ... }
这个逻辑还算正常, 继续找isLastAMRetry是怎么来的
public void shutDownJob() { ... //We are finishing cleanly so this is the last retry isLastAMRetry = true; // Stop all services // This will also send the final report to the ResourceManager LOG.info("Calling stop for all the services"); MRAppMaster.this.stop(); ... }
发现调用了shutDownJob,会把isLastAMRetry设置为true,调用shutDownJob是因为接收到JobFinishEvent事件。
我们多了一些信息,偷懒在issue继续搜索一下,看有没有人解决了。
这次找到issue了,https://issues.apache.org/jira/browse/MAPREDUCE-5086
阅读patch,发现之前忽略了RM报的一个错误。
org.apache.hadoop.yarn.exceptions.impl.pb.YarnRemoteExceptionPBImpl: Application doesn't exist in cache appattempt_1405852606905_0014_000001
结果
重启nodemanager导致RM的appattempt cache数组删除,JobImpl返回了InternalError,AM认为出错了就没必要重试了,直接置isLastRetry=true。
修改方式是加了一个状态,表明这是“RM重启”了(注意这里不是nodemanager重启,有一些关联),还可以继续重试。具体修改阅读patch https://issues.apache.org/jira/browse/MAPREDUCE-5086
最后,由于patch修改的版本和我们用的版本不一致,还得需要用我们使用的版本依照它的思路改一遍。
原文地址:hadoop重启Namenode时,appTokens报FileNotFoundException, 感谢原作者分享。