欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页  >  数据库

hadoop重启Namenode时,appTokens报FileNotFoundException

程序员文章站 2022-04-19 09:45:58
...

现象 报错如下 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修改的版本和我们用的版本不一致,还得需要用我们使用的版本依照它的思路改一遍。