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://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=/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修改的版本和我们用的版本不一致,还得需要用我们使用的版本依照它的思路改一遍。




fatkun

没有评论


You can leave the first : )



发表评论

电子邮件地址不会被公开。