Uploaded image for project: 'Hadoop YARN'
  1. Hadoop YARN
  2. YARN-2871

TestRMRestart#testRMRestartGetApplicationList sometime fails in trunk

    Details

    • Type: Test
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 2.8.0, 3.0.0-alpha1
    • Component/s: None
    • Labels:
      None

      Description

      From trunk build #746 (https://builds.apache.org/job/Hadoop-Yarn-trunk/746):

      Failed tests:
        TestRMRestart.testRMRestartGetApplicationList:957
      rMAppManager.logApplicationSummary(
          isA(org.apache.hadoop.yarn.api.records.ApplicationId)
      );
      Wanted 3 times:
      -> at org.apache.hadoop.yarn.server.resourcemanager.TestRMRestart.testRMRestartGetApplicationList(TestRMRestart.java:957)
      But was 2 times:
      -> at org.apache.hadoop.yarn.server.resourcemanager.RMAppManager.handle(RMAppManager.java:66)
      
      1. YARN-2871.002.patch
        2 kB
        zhihai xu
      2. YARN-2871.001.patch
        2 kB
        zhihai xu
      3. YARN-2871.000.patch
        1 kB
        zhihai xu

        Issue Links

          Activity

          Hide
          hudson Hudson added a comment -

          SUCCESS: Integrated in Hadoop-Mapreduce-trunk #2187 (See https://builds.apache.org/job/Hadoop-Mapreduce-trunk/2187/)
          YARN-2871. TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97)

          • hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          • hadoop-yarn-project/CHANGES.txt
          Show
          hudson Hudson added a comment - SUCCESS: Integrated in Hadoop-Mapreduce-trunk #2187 (See https://builds.apache.org/job/Hadoop-Mapreduce-trunk/2187/ ) YARN-2871 . TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97) hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java hadoop-yarn-project/CHANGES.txt
          Hide
          hudson Hudson added a comment -

          SUCCESS: Integrated in Hadoop-Mapreduce-trunk-Java8 #239 (See https://builds.apache.org/job/Hadoop-Mapreduce-trunk-Java8/239/)
          YARN-2871. TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97)

          • hadoop-yarn-project/CHANGES.txt
          • hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          Show
          hudson Hudson added a comment - SUCCESS: Integrated in Hadoop-Mapreduce-trunk-Java8 #239 (See https://builds.apache.org/job/Hadoop-Mapreduce-trunk-Java8/239/ ) YARN-2871 . TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97) hadoop-yarn-project/CHANGES.txt hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          Hide
          hudson Hudson added a comment -

          SUCCESS: Integrated in Hadoop-Hdfs-trunk #2169 (See https://builds.apache.org/job/Hadoop-Hdfs-trunk/2169/)
          YARN-2871. TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97)

          • hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          • hadoop-yarn-project/CHANGES.txt
          Show
          hudson Hudson added a comment - SUCCESS: Integrated in Hadoop-Hdfs-trunk #2169 (See https://builds.apache.org/job/Hadoop-Hdfs-trunk/2169/ ) YARN-2871 . TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97) hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java hadoop-yarn-project/CHANGES.txt
          Hide
          hudson Hudson added a comment -

          FAILURE: Integrated in Hadoop-Hdfs-trunk-Java8 #230 (See https://builds.apache.org/job/Hadoop-Hdfs-trunk-Java8/230/)
          YARN-2871. TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97)

          • hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          • hadoop-yarn-project/CHANGES.txt
          Show
          hudson Hudson added a comment - FAILURE: Integrated in Hadoop-Hdfs-trunk-Java8 #230 (See https://builds.apache.org/job/Hadoop-Hdfs-trunk-Java8/230/ ) YARN-2871 . TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97) hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java hadoop-yarn-project/CHANGES.txt
          Hide
          hudson Hudson added a comment -

          FAILURE: Integrated in Hadoop-Yarn-trunk #971 (See https://builds.apache.org/job/Hadoop-Yarn-trunk/971/)
          YARN-2871. TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97)

          • hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          • hadoop-yarn-project/CHANGES.txt
          Show
          hudson Hudson added a comment - FAILURE: Integrated in Hadoop-Yarn-trunk #971 (See https://builds.apache.org/job/Hadoop-Yarn-trunk/971/ ) YARN-2871 . TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97) hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java hadoop-yarn-project/CHANGES.txt
          Hide
          hudson Hudson added a comment -

          FAILURE: Integrated in Hadoop-Yarn-trunk-Java8 #241 (See https://builds.apache.org/job/Hadoop-Yarn-trunk-Java8/241/)
          YARN-2871. TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97)

          • hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          • hadoop-yarn-project/CHANGES.txt
          Show
          hudson Hudson added a comment - FAILURE: Integrated in Hadoop-Yarn-trunk-Java8 #241 (See https://builds.apache.org/job/Hadoop-Yarn-trunk-Java8/241/ ) YARN-2871 . TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97) hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java hadoop-yarn-project/CHANGES.txt
          Hide
          zxu zhihai xu added a comment -

          thanks Masatake Iwasaki for the review! thanks Xuan Gong for the review and committing the patch!

          Show
          zxu zhihai xu added a comment - thanks Masatake Iwasaki for the review! thanks Xuan Gong for the review and committing the patch!
          Hide
          hudson Hudson added a comment -

          FAILURE: Integrated in Hadoop-trunk-Commit #8076 (See https://builds.apache.org/job/Hadoop-trunk-Commit/8076/)
          YARN-2871. TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97)

          • hadoop-yarn-project/CHANGES.txt
          • hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          Show
          hudson Hudson added a comment - FAILURE: Integrated in Hadoop-trunk-Commit #8076 (See https://builds.apache.org/job/Hadoop-trunk-Commit/8076/ ) YARN-2871 . TestRMRestart#testRMRestartGetApplicationList sometime fails (xgong: rev fe6c1bd73aee188ed58df4d33bbc2d2fe0779a97) hadoop-yarn-project/CHANGES.txt hadoop-yarn-project/hadoop-yarn/hadoop-yarn-server/hadoop-yarn-server-resourcemanager/src/test/java/org/apache/hadoop/yarn/server/resourcemanager/TestRMRestart.java
          Hide
          xgong Xuan Gong added a comment -

          Committed into trunk/branch-2. Thanks, zhihai.

          Show
          xgong Xuan Gong added a comment - Committed into trunk/branch-2. Thanks, zhihai.
          Hide
          xgong Xuan Gong added a comment -

          +1 LGTM. Checking this in

          Show
          xgong Xuan Gong added a comment - +1 LGTM. Checking this in
          Hide
          iwasakims Masatake Iwasaki added a comment -

          I'm +1(non-binding) on this.

          Show
          iwasakims Masatake Iwasaki added a comment - I'm +1(non-binding) on this.
          Hide
          hadoopqa Hadoop QA added a comment -



          +1 overall



          Vote Subsystem Runtime Comment
          0 pre-patch 6m 43s Pre-patch trunk compilation is healthy.
          +1 @author 0m 0s The patch does not contain any @author tags.
          +1 tests included 0m 0s The patch appears to include 1 new or modified test files.
          +1 javac 7m 48s There were no new javac warning messages.
          +1 release audit 0m 18s The applied patch does not increase the total number of release audit warnings.
          +1 checkstyle 0m 46s There were no new checkstyle issues.
          +1 whitespace 0m 0s The patch has no lines that end in whitespace.
          +1 install 1m 33s mvn install still works.
          +1 eclipse:eclipse 0m 33s The patch built with eclipse:eclipse.
          +1 findbugs 1m 24s The patch does not introduce any new Findbugs (version 3.0.0) warnings.
          +1 yarn tests 51m 2s Tests passed in hadoop-yarn-server-resourcemanager.
              70m 10s  



          Subsystem Report/Notes
          Patch URL http://issues.apache.org/jira/secure/attachment/12742218/YARN-2871.002.patch
          Optional Tests javac unit findbugs checkstyle
          git revision trunk / aa07dea
          hadoop-yarn-server-resourcemanager test log https://builds.apache.org/job/PreCommit-YARN-Build/8360/artifact/patchprocess/testrun_hadoop-yarn-server-resourcemanager.txt
          Test Results https://builds.apache.org/job/PreCommit-YARN-Build/8360/testReport/
          Java 1.7.0_55
          uname Linux asf903.gq1.ygridcore.net 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
          Console output https://builds.apache.org/job/PreCommit-YARN-Build/8360/console

          This message was automatically generated.

          Show
          hadoopqa Hadoop QA added a comment - +1 overall Vote Subsystem Runtime Comment 0 pre-patch 6m 43s Pre-patch trunk compilation is healthy. +1 @author 0m 0s The patch does not contain any @author tags. +1 tests included 0m 0s The patch appears to include 1 new or modified test files. +1 javac 7m 48s There were no new javac warning messages. +1 release audit 0m 18s The applied patch does not increase the total number of release audit warnings. +1 checkstyle 0m 46s There were no new checkstyle issues. +1 whitespace 0m 0s The patch has no lines that end in whitespace. +1 install 1m 33s mvn install still works. +1 eclipse:eclipse 0m 33s The patch built with eclipse:eclipse. +1 findbugs 1m 24s The patch does not introduce any new Findbugs (version 3.0.0) warnings. +1 yarn tests 51m 2s Tests passed in hadoop-yarn-server-resourcemanager.     70m 10s   Subsystem Report/Notes Patch URL http://issues.apache.org/jira/secure/attachment/12742218/YARN-2871.002.patch Optional Tests javac unit findbugs checkstyle git revision trunk / aa07dea hadoop-yarn-server-resourcemanager test log https://builds.apache.org/job/PreCommit-YARN-Build/8360/artifact/patchprocess/testrun_hadoop-yarn-server-resourcemanager.txt Test Results https://builds.apache.org/job/PreCommit-YARN-Build/8360/testReport/ Java 1.7.0_55 uname Linux asf903.gq1.ygridcore.net 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux Console output https://builds.apache.org/job/PreCommit-YARN-Build/8360/console This message was automatically generated.
          Hide
          zxu zhihai xu added a comment -

          Masatake Iwasaki, thanks for the suggestion, it should work. I uploaded a new patch YARN-2871.002.patch based on your suggestion. Please review it.

          Show
          zxu zhihai xu added a comment - Masatake Iwasaki , thanks for the suggestion, it should work. I uploaded a new patch YARN-2871 .002.patch based on your suggestion. Please review it.
          Hide
          iwasakims Masatake Iwasaki added a comment -

          Thanks for the investigation, zhihai xu. I found that org.mockito.Mockito.timeout is used in some other tests using Mockito. It could be used here too.

          Show
          iwasakims Masatake Iwasaki added a comment - Thanks for the investigation, zhihai xu . I found that org.mockito.Mockito.timeout is used in some other tests using Mockito. It could be used here too.
          Hide
          zxu zhihai xu added a comment -

          Hi Xuan Gong, the latest patch passed Jenkins test, Could you review it? thanks

          Show
          zxu zhihai xu added a comment - Hi Xuan Gong , the latest patch passed Jenkins test, Could you review it? thanks
          Hide
          hadoopqa Hadoop QA added a comment -



          +1 overall



          Vote Subsystem Runtime Comment
          0 pre-patch 15m 51s Pre-patch trunk compilation is healthy.
          +1 @author 0m 0s The patch does not contain any @author tags.
          +1 tests included 0m 0s The patch appears to include 1 new or modified test files.
          +1 javac 7m 31s There were no new javac warning messages.
          +1 javadoc 9m 34s There were no new javadoc warning messages.
          +1 release audit 0m 23s The applied patch does not increase the total number of release audit warnings.
          +1 checkstyle 0m 46s There were no new checkstyle issues.
          +1 whitespace 0m 0s The patch has no lines that end in whitespace.
          +1 install 1m 34s mvn install still works.
          +1 eclipse:eclipse 0m 33s The patch built with eclipse:eclipse.
          +1 findbugs 1m 25s The patch does not introduce any new Findbugs (version 3.0.0) warnings.
          +1 yarn tests 50m 49s Tests passed in hadoop-yarn-server-resourcemanager.
              88m 30s  



          Subsystem Report/Notes
          Patch URL http://issues.apache.org/jira/secure/attachment/12741794/YARN-2871.001.patch
          Optional Tests javadoc javac unit findbugs checkstyle
          git revision trunk / a815cc1
          hadoop-yarn-server-resourcemanager test log https://builds.apache.org/job/PreCommit-YARN-Build/8341/artifact/patchprocess/testrun_hadoop-yarn-server-resourcemanager.txt
          Test Results https://builds.apache.org/job/PreCommit-YARN-Build/8341/testReport/
          Java 1.7.0_55
          uname Linux asf906.gq1.ygridcore.net 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
          Console output https://builds.apache.org/job/PreCommit-YARN-Build/8341/console

          This message was automatically generated.

          Show
          hadoopqa Hadoop QA added a comment - +1 overall Vote Subsystem Runtime Comment 0 pre-patch 15m 51s Pre-patch trunk compilation is healthy. +1 @author 0m 0s The patch does not contain any @author tags. +1 tests included 0m 0s The patch appears to include 1 new or modified test files. +1 javac 7m 31s There were no new javac warning messages. +1 javadoc 9m 34s There were no new javadoc warning messages. +1 release audit 0m 23s The applied patch does not increase the total number of release audit warnings. +1 checkstyle 0m 46s There were no new checkstyle issues. +1 whitespace 0m 0s The patch has no lines that end in whitespace. +1 install 1m 34s mvn install still works. +1 eclipse:eclipse 0m 33s The patch built with eclipse:eclipse. +1 findbugs 1m 25s The patch does not introduce any new Findbugs (version 3.0.0) warnings. +1 yarn tests 50m 49s Tests passed in hadoop-yarn-server-resourcemanager.     88m 30s   Subsystem Report/Notes Patch URL http://issues.apache.org/jira/secure/attachment/12741794/YARN-2871.001.patch Optional Tests javadoc javac unit findbugs checkstyle git revision trunk / a815cc1 hadoop-yarn-server-resourcemanager test log https://builds.apache.org/job/PreCommit-YARN-Build/8341/artifact/patchprocess/testrun_hadoop-yarn-server-resourcemanager.txt Test Results https://builds.apache.org/job/PreCommit-YARN-Build/8341/testReport/ Java 1.7.0_55 uname Linux asf906.gq1.ygridcore.net 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux Console output https://builds.apache.org/job/PreCommit-YARN-Build/8341/console This message was automatically generated.
          Hide
          hadoopqa Hadoop QA added a comment -



          +1 overall



          Vote Subsystem Runtime Comment
          0 pre-patch 18m 40s Pre-patch trunk compilation is healthy.
          +1 @author 0m 0s The patch does not contain any @author tags.
          +1 tests included 0m 0s The patch appears to include 1 new or modified test files.
          +1 javac 7m 48s There were no new javac warning messages.
          +1 javadoc 10m 18s There were no new javadoc warning messages.
          +1 release audit 0m 22s The applied patch does not increase the total number of release audit warnings.
          +1 checkstyle 0m 45s There were no new checkstyle issues.
          +1 whitespace 0m 0s The patch has no lines that end in whitespace.
          +1 install 1m 35s mvn install still works.
          +1 eclipse:eclipse 0m 33s The patch built with eclipse:eclipse.
          +1 findbugs 1m 25s The patch does not introduce any new Findbugs (version 3.0.0) warnings.
          +1 yarn tests 50m 50s Tests passed in hadoop-yarn-server-resourcemanager.
              92m 19s  



          Subsystem Report/Notes
          Patch URL http://issues.apache.org/jira/secure/attachment/12741787/YARN-2871.001.patch
          Optional Tests javadoc javac unit findbugs checkstyle
          git revision trunk / a815cc1
          hadoop-yarn-server-resourcemanager test log https://builds.apache.org/job/PreCommit-YARN-Build/8339/artifact/patchprocess/testrun_hadoop-yarn-server-resourcemanager.txt
          Test Results https://builds.apache.org/job/PreCommit-YARN-Build/8339/testReport/
          Java 1.7.0_55
          uname Linux asf903.gq1.ygridcore.net 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
          Console output https://builds.apache.org/job/PreCommit-YARN-Build/8339/console

          This message was automatically generated.

          Show
          hadoopqa Hadoop QA added a comment - +1 overall Vote Subsystem Runtime Comment 0 pre-patch 18m 40s Pre-patch trunk compilation is healthy. +1 @author 0m 0s The patch does not contain any @author tags. +1 tests included 0m 0s The patch appears to include 1 new or modified test files. +1 javac 7m 48s There were no new javac warning messages. +1 javadoc 10m 18s There were no new javadoc warning messages. +1 release audit 0m 22s The applied patch does not increase the total number of release audit warnings. +1 checkstyle 0m 45s There were no new checkstyle issues. +1 whitespace 0m 0s The patch has no lines that end in whitespace. +1 install 1m 35s mvn install still works. +1 eclipse:eclipse 0m 33s The patch built with eclipse:eclipse. +1 findbugs 1m 25s The patch does not introduce any new Findbugs (version 3.0.0) warnings. +1 yarn tests 50m 50s Tests passed in hadoop-yarn-server-resourcemanager.     92m 19s   Subsystem Report/Notes Patch URL http://issues.apache.org/jira/secure/attachment/12741787/YARN-2871.001.patch Optional Tests javadoc javac unit findbugs checkstyle git revision trunk / a815cc1 hadoop-yarn-server-resourcemanager test log https://builds.apache.org/job/PreCommit-YARN-Build/8339/artifact/patchprocess/testrun_hadoop-yarn-server-resourcemanager.txt Test Results https://builds.apache.org/job/PreCommit-YARN-Build/8339/testReport/ Java 1.7.0_55 uname Linux asf903.gq1.ygridcore.net 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux Console output https://builds.apache.org/job/PreCommit-YARN-Build/8339/console This message was automatically generated.
          Hide
          zxu zhihai xu added a comment -

          Masatake Iwasaki, thanks for the review. It looks like MockRM#waitForState won't meet my need, instead I check RMAppManager#completedAppsInStateStore to wait for less time in the new patch YARN-2871.001.patch.

          Show
          zxu zhihai xu added a comment - Masatake Iwasaki , thanks for the review. It looks like MockRM#waitForState won't meet my need, instead I check RMAppManager#completedAppsInStateStore to wait for less time in the new patch YARN-2871 .001.patch.
          Hide
          iwasakims Masatake Iwasaki added a comment -

          Thanks for working on this, zhihai xu! These intermittent test failures annoyed me these days.

          980	    Thread.sleep(1000);
          

          Is it possible to use MockRM#waitForState to wait for the application state is recovered? Sleeping fixed time is not certain and it makes test time longer unnecessary, though there are many lines calling Thread#sleep in the test...

          Show
          iwasakims Masatake Iwasaki added a comment - Thanks for working on this, zhihai xu ! These intermittent test failures annoyed me these days. 980 Thread .sleep(1000); Is it possible to use MockRM#waitForState to wait for the application state is recovered? Sleeping fixed time is not certain and it makes test time longer unnecessary, though there are many lines calling Thread#sleep in the test...
          Hide
          hadoopqa Hadoop QA added a comment -



          +1 overall



          Vote Subsystem Runtime Comment
          0 pre-patch 6m 41s Pre-patch trunk compilation is healthy.
          +1 @author 0m 0s The patch does not contain any @author tags.
          +1 tests included 0m 0s The patch appears to include 1 new or modified test files.
          +1 javac 7m 41s There were no new javac warning messages.
          +1 release audit 0m 20s The applied patch does not increase the total number of release audit warnings.
          +1 checkstyle 0m 45s There were no new checkstyle issues.
          +1 whitespace 0m 0s The patch has no lines that end in whitespace.
          +1 install 1m 31s mvn install still works.
          +1 eclipse:eclipse 0m 32s The patch built with eclipse:eclipse.
          +1 findbugs 1m 25s The patch does not introduce any new Findbugs (version 3.0.0) warnings.
          +1 yarn tests 50m 40s Tests passed in hadoop-yarn-server-resourcemanager.
              69m 38s  



          Subsystem Report/Notes
          Patch URL http://issues.apache.org/jira/secure/attachment/12741254/YARN-2871.000.patch
          Optional Tests javac unit findbugs checkstyle
          git revision trunk / 41ae776
          hadoop-yarn-server-resourcemanager test log https://builds.apache.org/job/PreCommit-YARN-Build/8324/artifact/patchprocess/testrun_hadoop-yarn-server-resourcemanager.txt
          Test Results https://builds.apache.org/job/PreCommit-YARN-Build/8324/testReport/
          Java 1.7.0_55
          uname Linux asf907.gq1.ygridcore.net 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
          Console output https://builds.apache.org/job/PreCommit-YARN-Build/8324/console

          This message was automatically generated.

          Show
          hadoopqa Hadoop QA added a comment - +1 overall Vote Subsystem Runtime Comment 0 pre-patch 6m 41s Pre-patch trunk compilation is healthy. +1 @author 0m 0s The patch does not contain any @author tags. +1 tests included 0m 0s The patch appears to include 1 new or modified test files. +1 javac 7m 41s There were no new javac warning messages. +1 release audit 0m 20s The applied patch does not increase the total number of release audit warnings. +1 checkstyle 0m 45s There were no new checkstyle issues. +1 whitespace 0m 0s The patch has no lines that end in whitespace. +1 install 1m 31s mvn install still works. +1 eclipse:eclipse 0m 32s The patch built with eclipse:eclipse. +1 findbugs 1m 25s The patch does not introduce any new Findbugs (version 3.0.0) warnings. +1 yarn tests 50m 40s Tests passed in hadoop-yarn-server-resourcemanager.     69m 38s   Subsystem Report/Notes Patch URL http://issues.apache.org/jira/secure/attachment/12741254/YARN-2871.000.patch Optional Tests javac unit findbugs checkstyle git revision trunk / 41ae776 hadoop-yarn-server-resourcemanager test log https://builds.apache.org/job/PreCommit-YARN-Build/8324/artifact/patchprocess/testrun_hadoop-yarn-server-resourcemanager.txt Test Results https://builds.apache.org/job/PreCommit-YARN-Build/8324/testReport/ Java 1.7.0_55 uname Linux asf907.gq1.ygridcore.net 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux Console output https://builds.apache.org/job/PreCommit-YARN-Build/8324/console This message was automatically generated.
          Hide
          zxu zhihai xu added a comment -

          I uploaded a patch YARN-2871.000.patch for review.

          Show
          zxu zhihai xu added a comment - I uploaded a patch YARN-2871 .000.patch for review.
          Hide
          zxu zhihai xu added a comment -

          I can work on this issue, Based on the failure logs https://builds.apache.org/job/PreCommit-YARN-Build/8323/testReport/org.apache.hadoop.yarn.server.resourcemanager/TestRMRestart/testRMRestartGetApplicationList_1_/, the root cause of this issue is a race condition in the test. logApplicationSummary is called when RMAppManager handles APP_COMPLETED RMAppManagerEvent. RMAppImpl sends APP_COMPLETED event to AsyncDispatcher thread. If AsyncDispatcher thread doesn't process APP_COMPLETED event on time, then the test will fail. I think If we add some delay before the verification, it will fix this issue.
          The important logs from failed test:

          2015-06-23 06:06:20,484 INFO  [Thread-693] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(572)) - Recovery started
          2015-06-23 06:06:20,484 INFO  [Thread-693] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:recover(178)) - recovering RMDelegationTokenSecretManager.
          2015-06-23 06:06:20,484 INFO  [Thread-693] resourcemanager.RMAppManager (RMAppManager.java:recover(425)) - Recovering 3 applications
          2015-06-23 06:06:20,485 DEBUG [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435039562888_0001 of type RECOVER
          2015-06-23 06:06:20,485 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435039562888_0001 with 1 attempts and final state = FINISHED
          2015-06-23 06:06:20,485 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435039562888_0001_000001 with final state: FINISHED
          2015-06-23 06:06:20,485 DEBUG [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435039562888_0001_000001 of type RECOVER
          2015-06-23 06:06:20,486 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435039562888_0001_000001 State change from NEW to FINISHED
          2015-06-23 06:06:20,486 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435039562888_0001 State change from NEW to FINISHED
          2015-06-23 06:06:20,486 DEBUG [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435039562888_0002 of type RECOVER
          2015-06-23 06:06:20,486 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435039562888_0002 with 1 attempts and final state = FAILED
          2015-06-23 06:06:20,487 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435039562888_0002_000001 with final state: FAILED
          2015-06-23 06:06:20,487 DEBUG [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435039562888_0002_000001 of type RECOVER
          2015-06-23 06:06:20,487 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435039562888_0002_000001 State change from NEW to FAILED
          2015-06-23 06:06:20,487 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435039562888_0002 State change from NEW to FAILED
          2015-06-23 06:06:20,488 DEBUG [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435039562888_0003 of type RECOVER
          2015-06-23 06:06:20,488 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435039562888_0003 with 1 attempts and final state = KILLED
          2015-06-23 06:06:20,488 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435039562888_0003_000001 with final state: KILLED
          2015-06-23 06:06:20,489 DEBUG [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435039562888_0003_000001 of type RECOVER
          2015-06-23 06:06:20,489 INFO  [Thread-693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435039562888_0003_000001 State change from NEW to KILLED
          2015-06-23 06:06:20,489 INFO  [Thread-693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435039562888_0003 State change from NEW to KILLED
          2015-06-23 06:06:20,489 INFO  [Thread-693] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(579)) - Recovery ended
          2015-06-23 06:06:20,489 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115)) - RMActiveServices: starting services, size=15
          2015-06-23 06:06:20,489 INFO  [Thread-693] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(105)) - Rolling master-key for container-tokens
          2015-06-23 06:06:20,489 INFO  [Thread-693] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(110)) - Going to activate master-key with key-id -644495556 in 900000ms
          2015-06-23 06:06:20,489 INFO  [Thread-693] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(95)) - Rolling master-key for nm-tokens
          2015-06-23 06:06:20,489 INFO  [Thread-693] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(100)) - Going to activate master-key with key-id 1471860283 in 900000ms
          2015-06-23 06:06:20,490 INFO  [Thread-693] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master key for generating delegation tokens
          2015-06-23 06:06:20,490 INFO  [Thread-693] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID 3
          2015-06-23 06:06:20,490 DEBUG [Thread-693] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832)) - Processing event of type STORE_MASTERKEY
          2015-06-23 06:06:20,490 INFO  [Thread-693] recovery.RMStateStore (RMStateStore.java:transition(365)) - Storing RMDTMasterKey.
          2015-06-23 06:06:20,490 INFO  [Thread-693] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213)) - Store RMDT master key with key id: 3. Currently rmDTMasterKeyState size: 3
          2015-06-23 06:06:20,490 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.RMSecretManagerService is started
          2015-06-23 06:06:20,490 INFO  [Thread[Thread-717,5,main]] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:run(649)) - Starting expired delegation token remover thread, tokenRemoverScanInterval=60 min(s)
          2015-06-23 06:06:20,491 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.ContainerAllocationExpirer is started
          2015-06-23 06:06:20,491 INFO  [Thread[Thread-717,5,main]] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master key for generating delegation tokens
          2015-06-23 06:06:20,492 INFO  [Thread[Thread-717,5,main]] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID 4
          2015-06-23 06:06:20,492 DEBUG [Thread[Thread-717,5,main]] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832)) - Processing event of type STORE_MASTERKEY
          2015-06-23 06:06:20,492 INFO  [Thread[Thread-717,5,main]] recovery.RMStateStore (RMStateStore.java:transition(365)) - Storing RMDTMasterKey.
          2015-06-23 06:06:20,492 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service AMLivelinessMonitor is started
          2015-06-23 06:06:20,492 INFO  [Thread[Thread-717,5,main]] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213)) - Store RMDT master key with key id: 4. Currently rmDTMasterKeyState size: 4
          2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service AMLivelinessMonitor is started
          2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.nodelabels.CommonNodeLabelsManager is started
          2015-06-23 06:06:20,493 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter: starting services, size=0
          2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter is started
          2015-06-23 06:06:20,493 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: starting services, size=0
          2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher is started
          2015-06-23 06:06:20,493 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.NodesListManager is started
          2015-06-23 06:06:20,494 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.AllocationFileLoaderService is started
          2015-06-23 06:06:20,494 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler is started
          2015-06-23 06:06:20,494 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$SchedulerEventDispatcher is started
          2015-06-23 06:06:20,494 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service NMLivelinessMonitor is started
          2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService is started
          2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService is started
          2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ClientRMService is started
          2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.amlauncher.ApplicationMasterLauncher is started
          2015-06-23 06:06:20,495 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service RMActiveServices is started
          2015-06-23 06:06:20,495 INFO  [Thread-693] resourcemanager.ResourceManager (ResourceManager.java:transitionToActive(1049)) - Transitioned to active state
          2015-06-23 06:06:20,495 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115)) - ResourceManager: starting services, size=2
          2015-06-23 06:06:20,496 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service Dispatcher is started
          2015-06-23 06:06:20,496 DEBUG [Thread-693] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.AdminService: starting services, size=0
          2015-06-23 06:06:20,496 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.AdminService is started
          2015-06-23 06:06:20,496 DEBUG [Thread-693] service.AbstractService (AbstractService.java:start(197)) - Service ResourceManager is started
          2015-06-23 06:06:20,496 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED
          2015-06-23 06:06:20,496 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0003 owned by user
          2015-06-23 06:06:20,497 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
          2015-06-23 06:06:20,497 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
          2015-06-23 06:06:20,497 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
          2015-06-23 06:06:20,497 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0002 owned by user
          2015-06-23 06:06:20,497 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0001 of type APP_COMPLETED
          2015-06-23 06:06:20,498 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
          2015-06-23 06:06:20,498 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
          2015-06-23 06:06:20,498 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
          2015-06-23 06:06:20,498 INFO  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logSuccess(148)) - USER=user	OPERATION=Application Finished - Succeeded	TARGET=RMAppManager	RESULT=SUCCESS	APPID=application_1435039562888_0001
          2015-06-23 06:06:20,498 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0001 owned by user
          2015-06-23 06:06:20,498 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
          2015-06-23 06:06:20,499 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
          2015-06-23 06:06:20,499 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
          2015-06-23 06:06:20,499 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
          2015-06-23 06:06:20,499 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0001,name=name,user=user,queue=default,state=FINISHED,trackingUrl=http://asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0001/,appMasterHost=N/A,startTime=1435039562899,finishTime=1435039567908,finalStatus=SUCCEEDED,memorySeconds=3586,vcoreSeconds=3,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType
          2015-06-23 06:06:20,499 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0003 owned by user
          2015-06-23 06:06:20,499 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED
          2015-06-23 06:06:20,500 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0002 of type APP_COMPLETED
          2015-06-23 06:06:20,500 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
          2015-06-23 06:06:20,500 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
          2015-06-23 06:06:20,500 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
          2015-06-23 06:06:20,500 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0002 owned by user
          2015-06-23 06:06:20,500 WARN  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logFailure(263)) - USER=user	OPERATION=Application Finished - Failed	TARGET=RMAppManager	RESULT=FAILURE	DESCRIPTION=App failed with state: FAILED	PERMISSIONS=Application application_1435039562888_0002 failed 1 times due to AM Container for appattempt_1435039562888_0002_000001 exited with  exitCode: 0
          Failing this attempt.Diagnostics: SuccessFor more detailed output, check the application tracking page: http://asf906.gq1.ygridcore.net:8088/cluster/app/application_1435039562888_0002 Then click on links to logs of each attempt.
          . Failing the application.	APPID=application_1435039562888_0002
          2015-06-23 06:06:20,501 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
          2015-06-23 06:06:20,501 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
          2015-06-23 06:06:20,501 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
          2015-06-23 06:06:20,501 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001
          2015-06-23 06:06:20,501 DEBUG [Thread-693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0001 owned by user
          2015-06-23 06:06:20,501 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0002,name=name,user=user,queue=default,state=FAILED,trackingUrl=http://asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0002/,appMasterHost=N/A,startTime=1435039569909,finishTime=1435039573919,finalStatus=FAILED,memorySeconds=2564,vcoreSeconds=2,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType
          2015-06-23 06:06:20,502 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
          2015-06-23 06:06:20,502 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
          2015-06-23 06:06:20,502 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED
          2015-06-23 06:06:20,502 DEBUG [Thread-693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001
          2015-06-23 06:06:20,502 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0003 of type APP_COMPLETED
          2015-06-23 06:06:20,502 INFO  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logSuccess(148)) - USER=user	OPERATION=Application Finished - Killed	TARGET=RMAppManager	RESULT=SUCCESS	APPID=application_1435039562888_0003
          2015-06-23 06:06:20,503 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001
          2015-06-23 06:06:20,503 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0003,name=name,user=user,queue=default,state=KILLED,trackingUrl=http://asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0003/,appMasterHost=N/A,startTime=1435039574916,finishTime=1435039578925,finalStatus=KILLED,memorySeconds=6,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType
          2015-06-23 06:06:20,508 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452)) - Service: ResourceManager entered state STOPPED
          

          From above logs, you can see RMAppManager processing event for application_1435039562888_0003 of type APP_COMPLETED is after all Verifying access-type VIEW_APP which is called from rm2.getClientRMService().getApplications.

          The corresponding logs from succeeded test:

          2015-06-22 23:45:01,319 INFO  [Thread-1] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(572)) - Recovery started
          2015-06-22 23:45:01,320 INFO  [Thread-1] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:recover(178)) - recovering RMDelegationTokenSecretManager.
          2015-06-22 23:45:01,348 INFO  [Thread-1] resourcemanager.RMAppManager (RMAppManager.java:recover(425)) - Recovering 3 applications
          2015-06-22 23:45:01,349 DEBUG [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435041883856_0001 of type RECOVER
          2015-06-22 23:45:01,349 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435041883856_0001 with 1 attempts and final state = FINISHED
          2015-06-22 23:45:01,350 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435041883856_0001_000001 with final state: FINISHED
          2015-06-22 23:45:01,351 DEBUG [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435041883856_0001_000001 of type RECOVER
          2015-06-22 23:45:01,351 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435041883856_0001_000001 State change from NEW to FINISHED
          2015-06-22 23:45:01,351 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0001 State change from NEW to FINISHED
          2015-06-22 23:45:01,352 DEBUG [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435041883856_0002 of type RECOVER
          2015-06-22 23:45:01,352 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435041883856_0002 with 1 attempts and final state = FAILED
          2015-06-22 23:45:01,353 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435041883856_0002_000001 with final state: FAILED
          2015-06-22 23:45:01,353 DEBUG [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435041883856_0002_000001 of type RECOVER
          2015-06-22 23:45:01,354 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435041883856_0002_000001 State change from NEW to FAILED
          2015-06-22 23:45:01,354 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0002 State change from NEW to FAILED
          2015-06-22 23:45:01,354 DEBUG [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435041883856_0003 of type RECOVER
          2015-06-22 23:45:01,354 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435041883856_0003 with 1 attempts and final state = KILLED
          2015-06-22 23:45:01,355 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435041883856_0003_000001 with final state: KILLED
          2015-06-22 23:45:01,356 DEBUG [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435041883856_0003_000001 of type RECOVER
          2015-06-22 23:45:01,356 INFO  [Thread-1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435041883856_0003_000001 State change from NEW to KILLED
          2015-06-22 23:45:01,356 INFO  [Thread-1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0003 State change from NEW to KILLED
          2015-06-22 23:45:01,356 INFO  [Thread-1] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(579)) - Recovery ended
          2015-06-22 23:45:01,356 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115)) - RMActiveServices: starting services, size=15
          2015-06-22 23:45:01,356 INFO  [Thread-1] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(105)) - Rolling master-key for container-tokens
          2015-06-22 23:45:01,356 INFO  [Thread-1] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(110)) - Going to activate master-key with key-id 344850257 in 900000ms
          2015-06-22 23:45:01,357 INFO  [Thread-1] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(95)) - Rolling master-key for nm-tokens
          2015-06-22 23:45:01,357 INFO  [Thread-1] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(100)) - Going to activate master-key with key-id -867844649 in 900000ms
          2015-06-22 23:45:01,357 INFO  [Thread-1] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master key for generating delegation tokens
          2015-06-22 23:45:01,357 INFO  [Thread-1] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID 3
          2015-06-22 23:45:01,357 DEBUG [Thread-1] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832)) - Processing event of type STORE_MASTERKEY
          2015-06-22 23:45:01,357 INFO  [Thread-1] recovery.RMStateStore (RMStateStore.java:transition(365)) - Storing RMDTMasterKey.
          2015-06-22 23:45:01,357 INFO  [Thread-1] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213)) - Store RMDT master key with key id: 3. Currently rmDTMasterKeyState size: 3
          2015-06-22 23:45:01,358 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.RMSecretManagerService is started
          2015-06-22 23:45:01,358 INFO  [Thread[Thread-21,5,main]] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:run(649)) - Starting expired delegation token remover thread, tokenRemoverScanInterval=60 min(s)
          2015-06-22 23:45:01,358 INFO  [Thread[Thread-21,5,main]] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master key for generating delegation tokens
          2015-06-22 23:45:01,358 INFO  [Thread[Thread-21,5,main]] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID 4
          2015-06-22 23:45:01,358 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.ContainerAllocationExpirer is started
          2015-06-22 23:45:01,359 DEBUG [Thread[Thread-21,5,main]] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832)) - Processing event of type STORE_MASTERKEY
          2015-06-22 23:45:01,359 INFO  [Thread[Thread-21,5,main]] recovery.RMStateStore (RMStateStore.java:transition(365)) - Storing RMDTMasterKey.
          2015-06-22 23:45:01,359 INFO  [Thread[Thread-21,5,main]] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213)) - Store RMDT master key with key id: 4. Currently rmDTMasterKeyState size: 4
          2015-06-22 23:45:01,359 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service AMLivelinessMonitor is started
          2015-06-22 23:45:01,359 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service AMLivelinessMonitor is started
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.nodelabels.CommonNodeLabelsManager is started
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter: starting services, size=0
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter is started
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: starting services, size=0
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher is started
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.NodesListManager is started
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler is started
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$SchedulerEventDispatcher is started
          2015-06-22 23:45:01,360 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service NMLivelinessMonitor is started
          2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService is started
          2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService is started
          2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ClientRMService is started
          2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.amlauncher.ApplicationMasterLauncher is started
          2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service RMActiveServices is started
          2015-06-22 23:45:01,361 INFO  [Thread-1] resourcemanager.ResourceManager (ResourceManager.java:transitionToActive(1049)) - Transitioned to active state
          2015-06-22 23:45:01,361 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115)) - ResourceManager: starting services, size=2
          2015-06-22 23:45:01,361 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service Dispatcher is started
          2015-06-22 23:45:01,361 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED
          2015-06-22 23:45:01,361 DEBUG [Thread-1] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.AdminService: starting services, size=0
          2015-06-22 23:45:01,362 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.AdminService is started
          2015-06-22 23:45:01,362 DEBUG [Thread-1] service.AbstractService (AbstractService.java:start(197)) - Service ResourceManager is started
          2015-06-22 23:45:01,363 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0001 of type APP_COMPLETED
          2015-06-22 23:45:01,363 INFO  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logSuccess(148)) - USER=user	OPERATION=Application Finished - Succeeded	TARGET=RMAppManager	RESULT=SUCCESS	APPID=application_1435041883856_0001
          2015-06-22 23:45:01,363 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
          2015-06-22 23:45:01,364 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0001,name=name,user=user,queue=default,state=FINISHED,trackingUrl=http://zxu-mbp.local:8088/proxy/application_1435041883856_0001/,appMasterHost=N/A,startTime=1435041884030,finishTime=1435041888611,finalStatus=SUCCEEDED,memorySeconds=112,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType
          2015-06-22 23:45:01,365 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED
          2015-06-22 23:45:01,365 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0002 of type APP_COMPLETED
          2015-06-22 23:45:01,365 WARN  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logFailure(263)) - USER=user	OPERATION=Application Finished - Failed	TARGET=RMAppManager	RESULT=FAILURE	DESCRIPTION=App failed with state: FAILED	PERMISSIONS=Application application_1435041883856_0002 failed 1 times due to AM Container for appattempt_1435041883856_0002_000001 exited with  exitCode: 0
          Failing this attempt.Diagnostics: SuccessFor more detailed output, check the application tracking page: http://zxu-mbp.local:8088/cluster/app/application_1435041883856_0002 Then click on links to logs of each attempt.
          . Failing the application.	APPID=application_1435041883856_0002
          2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
          2015-06-22 23:45:01,366 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0002,name=name,user=user,queue=default,state=FAILED,trackingUrl=http://zxu-mbp.local:8088/proxy/application_1435041883856_0002/,appMasterHost=N/A,startTime=1435041890627,finishTime=1435041894642,finalStatus=FAILED,memorySeconds=2565,vcoreSeconds=2,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType
          2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED
          2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0003 of type APP_COMPLETED
          2015-06-22 23:45:01,367 INFO  [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logSuccess(148)) - USER=user	OPERATION=Application Finished - Killed	TARGET=RMAppManager	RESULT=SUCCESS	APPID=application_1435041883856_0003
          2015-06-22 23:45:01,367 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
          2015-06-22 23:45:01,368 INFO  [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0003,name=name,user=user,queue=default,state=KILLED,trackingUrl=http://zxu-mbp.local:8088/proxy/application_1435041883856_0003/,appMasterHost=N/A,startTime=1435041895640,finishTime=1435041899657,finalStatus=KILLED,memorySeconds=18,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType
          2015-06-22 23:45:01,368 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0001 owned by user
          2015-06-22 23:45:01,370 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
          2015-06-22 23:45:01,370 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
          2015-06-22 23:45:01,370 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
          2015-06-22 23:45:01,376 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0002 owned by user
          2015-06-22 23:45:01,377 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
          2015-06-22 23:45:01,377 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
          2015-06-22 23:45:01,377 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
          2015-06-22 23:45:01,378 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0003 owned by user
          2015-06-22 23:45:01,378 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
          2015-06-22 23:45:01,379 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
          2015-06-22 23:45:01,379 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
          2015-06-22 23:45:01,382 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0001 owned by user
          2015-06-22 23:45:01,384 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
          2015-06-22 23:45:01,384 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
          2015-06-22 23:45:01,384 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001
          2015-06-22 23:45:01,384 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0002 owned by user
          2015-06-22 23:45:01,386 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
          2015-06-22 23:45:01,386 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
          2015-06-22 23:45:01,386 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001
          2015-06-22 23:45:01,386 DEBUG [Thread-1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0003 owned by user
          2015-06-22 23:45:01,387 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
          2015-06-22 23:45:01,387 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
          2015-06-22 23:45:01,387 DEBUG [Thread-1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001
          2015-06-22 23:45:01,395 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452)) - Service: ResourceManager entered state STOPPED
          

          From above logs, you can see RMAppManager processing event for application_1435041883856_0003 of type APP_COMPLETED is before Verifying access-type VIEW_APP.

          Show
          zxu zhihai xu added a comment - I can work on this issue, Based on the failure logs https://builds.apache.org/job/PreCommit-YARN-Build/8323/testReport/org.apache.hadoop.yarn.server.resourcemanager/TestRMRestart/testRMRestartGetApplicationList_1_/ , the root cause of this issue is a race condition in the test. logApplicationSummary is called when RMAppManager handles APP_COMPLETED RMAppManagerEvent. RMAppImpl sends APP_COMPLETED event to AsyncDispatcher thread. If AsyncDispatcher thread doesn't process APP_COMPLETED event on time, then the test will fail. I think If we add some delay before the verification, it will fix this issue. The important logs from failed test: 2015-06-23 06:06:20,484 INFO [ Thread -693] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(572)) - Recovery started 2015-06-23 06:06:20,484 INFO [ Thread -693] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:recover(178)) - recovering RMDelegationTokenSecretManager. 2015-06-23 06:06:20,484 INFO [ Thread -693] resourcemanager.RMAppManager (RMAppManager.java:recover(425)) - Recovering 3 applications 2015-06-23 06:06:20,485 DEBUG [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435039562888_0001 of type RECOVER 2015-06-23 06:06:20,485 INFO [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435039562888_0001 with 1 attempts and final state = FINISHED 2015-06-23 06:06:20,485 INFO [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435039562888_0001_000001 with final state: FINISHED 2015-06-23 06:06:20,485 DEBUG [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435039562888_0001_000001 of type RECOVER 2015-06-23 06:06:20,486 INFO [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435039562888_0001_000001 State change from NEW to FINISHED 2015-06-23 06:06:20,486 INFO [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435039562888_0001 State change from NEW to FINISHED 2015-06-23 06:06:20,486 DEBUG [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435039562888_0002 of type RECOVER 2015-06-23 06:06:20,486 INFO [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435039562888_0002 with 1 attempts and final state = FAILED 2015-06-23 06:06:20,487 INFO [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435039562888_0002_000001 with final state: FAILED 2015-06-23 06:06:20,487 DEBUG [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435039562888_0002_000001 of type RECOVER 2015-06-23 06:06:20,487 INFO [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435039562888_0002_000001 State change from NEW to FAILED 2015-06-23 06:06:20,487 INFO [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435039562888_0002 State change from NEW to FAILED 2015-06-23 06:06:20,488 DEBUG [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435039562888_0003 of type RECOVER 2015-06-23 06:06:20,488 INFO [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435039562888_0003 with 1 attempts and final state = KILLED 2015-06-23 06:06:20,488 INFO [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435039562888_0003_000001 with final state: KILLED 2015-06-23 06:06:20,489 DEBUG [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435039562888_0003_000001 of type RECOVER 2015-06-23 06:06:20,489 INFO [ Thread -693] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435039562888_0003_000001 State change from NEW to KILLED 2015-06-23 06:06:20,489 INFO [ Thread -693] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435039562888_0003 State change from NEW to KILLED 2015-06-23 06:06:20,489 INFO [ Thread -693] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(579)) - Recovery ended 2015-06-23 06:06:20,489 DEBUG [ Thread -693] service.CompositeService (CompositeService.java:serviceStart(115)) - RMActiveServices: starting services, size=15 2015-06-23 06:06:20,489 INFO [ Thread -693] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(105)) - Rolling master-key for container-tokens 2015-06-23 06:06:20,489 INFO [ Thread -693] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(110)) - Going to activate master-key with key-id -644495556 in 900000ms 2015-06-23 06:06:20,489 INFO [ Thread -693] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(95)) - Rolling master-key for nm-tokens 2015-06-23 06:06:20,489 INFO [ Thread -693] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(100)) - Going to activate master-key with key-id 1471860283 in 900000ms 2015-06-23 06:06:20,490 INFO [ Thread -693] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master key for generating delegation tokens 2015-06-23 06:06:20,490 INFO [ Thread -693] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID 3 2015-06-23 06:06:20,490 DEBUG [ Thread -693] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832)) - Processing event of type STORE_MASTERKEY 2015-06-23 06:06:20,490 INFO [ Thread -693] recovery.RMStateStore (RMStateStore.java:transition(365)) - Storing RMDTMasterKey. 2015-06-23 06:06:20,490 INFO [ Thread -693] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213)) - Store RMDT master key with key id: 3. Currently rmDTMasterKeyState size: 3 2015-06-23 06:06:20,490 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.RMSecretManagerService is started 2015-06-23 06:06:20,490 INFO [ Thread [ Thread -717,5,main]] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:run(649)) - Starting expired delegation token remover thread, tokenRemoverScanInterval=60 min(s) 2015-06-23 06:06:20,491 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.ContainerAllocationExpirer is started 2015-06-23 06:06:20,491 INFO [ Thread [ Thread -717,5,main]] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master key for generating delegation tokens 2015-06-23 06:06:20,492 INFO [ Thread [ Thread -717,5,main]] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID 4 2015-06-23 06:06:20,492 DEBUG [ Thread [ Thread -717,5,main]] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832)) - Processing event of type STORE_MASTERKEY 2015-06-23 06:06:20,492 INFO [ Thread [ Thread -717,5,main]] recovery.RMStateStore (RMStateStore.java:transition(365)) - Storing RMDTMasterKey. 2015-06-23 06:06:20,492 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service AMLivelinessMonitor is started 2015-06-23 06:06:20,492 INFO [ Thread [ Thread -717,5,main]] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213)) - Store RMDT master key with key id: 4. Currently rmDTMasterKeyState size: 4 2015-06-23 06:06:20,493 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service AMLivelinessMonitor is started 2015-06-23 06:06:20,493 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.nodelabels.CommonNodeLabelsManager is started 2015-06-23 06:06:20,493 DEBUG [ Thread -693] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter: starting services, size=0 2015-06-23 06:06:20,493 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter is started 2015-06-23 06:06:20,493 DEBUG [ Thread -693] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: starting services, size=0 2015-06-23 06:06:20,493 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher is started 2015-06-23 06:06:20,493 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.NodesListManager is started 2015-06-23 06:06:20,494 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.AllocationFileLoaderService is started 2015-06-23 06:06:20,494 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.fair.FairScheduler is started 2015-06-23 06:06:20,494 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$SchedulerEventDispatcher is started 2015-06-23 06:06:20,494 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service NMLivelinessMonitor is started 2015-06-23 06:06:20,495 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService is started 2015-06-23 06:06:20,495 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService is started 2015-06-23 06:06:20,495 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ClientRMService is started 2015-06-23 06:06:20,495 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.amlauncher.ApplicationMasterLauncher is started 2015-06-23 06:06:20,495 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service RMActiveServices is started 2015-06-23 06:06:20,495 INFO [ Thread -693] resourcemanager.ResourceManager (ResourceManager.java:transitionToActive(1049)) - Transitioned to active state 2015-06-23 06:06:20,495 DEBUG [ Thread -693] service.CompositeService (CompositeService.java:serviceStart(115)) - ResourceManager: starting services, size=2 2015-06-23 06:06:20,496 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service Dispatcher is started 2015-06-23 06:06:20,496 DEBUG [ Thread -693] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.AdminService: starting services, size=0 2015-06-23 06:06:20,496 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.AdminService is started 2015-06-23 06:06:20,496 DEBUG [ Thread -693] service.AbstractService (AbstractService.java:start(197)) - Service ResourceManager is started 2015-06-23 06:06:20,496 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED 2015-06-23 06:06:20,496 DEBUG [ Thread -693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0003 owned by user 2015-06-23 06:06:20,497 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001 2015-06-23 06:06:20,497 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001 2015-06-23 06:06:20,497 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001 2015-06-23 06:06:20,497 DEBUG [ Thread -693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0002 owned by user 2015-06-23 06:06:20,497 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0001 of type APP_COMPLETED 2015-06-23 06:06:20,498 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001 2015-06-23 06:06:20,498 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001 2015-06-23 06:06:20,498 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001 2015-06-23 06:06:20,498 INFO [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logSuccess(148)) - USER=user OPERATION=Application Finished - Succeeded TARGET=RMAppManager RESULT=SUCCESS APPID=application_1435039562888_0001 2015-06-23 06:06:20,498 DEBUG [ Thread -693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0001 owned by user 2015-06-23 06:06:20,498 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001 2015-06-23 06:06:20,499 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001 2015-06-23 06:06:20,499 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001 2015-06-23 06:06:20,499 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001 2015-06-23 06:06:20,499 INFO [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0001,name=name,user=user,queue= default ,state=FINISHED,trackingUrl=http: //asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0001/,appMasterHost=N/A,startTime=1435039562899,finishTime=1435039567908,finalStatus=SUCCEEDED,memorySeconds=3586,vcoreSeconds=3,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType 2015-06-23 06:06:20,499 DEBUG [ Thread -693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0003 owned by user 2015-06-23 06:06:20,499 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED 2015-06-23 06:06:20,500 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0002 of type APP_COMPLETED 2015-06-23 06:06:20,500 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001 2015-06-23 06:06:20,500 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001 2015-06-23 06:06:20,500 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001 2015-06-23 06:06:20,500 DEBUG [ Thread -693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0002 owned by user 2015-06-23 06:06:20,500 WARN [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logFailure(263)) - USER=user OPERATION=Application Finished - Failed TARGET=RMAppManager RESULT=FAILURE DESCRIPTION=App failed with state: FAILED PERMISSIONS=Application application_1435039562888_0002 failed 1 times due to AM Container for appattempt_1435039562888_0002_000001 exited with exitCode: 0 Failing this attempt.Diagnostics: SuccessFor more detailed output, check the application tracking page: http: //asf906.gq1.ygridcore.net:8088/cluster/app/application_1435039562888_0002 Then click on links to logs of each attempt. . Failing the application. APPID=application_1435039562888_0002 2015-06-23 06:06:20,501 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001 2015-06-23 06:06:20,501 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001 2015-06-23 06:06:20,501 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001 2015-06-23 06:06:20,501 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0002_000001 2015-06-23 06:06:20,501 DEBUG [ Thread -693] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for jenkins (auth:KERBEROS) on application application_1435039562888_0001 owned by user 2015-06-23 06:06:20,501 INFO [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0002,name=name,user=user,queue= default ,state=FAILED,trackingUrl=http: //asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0002/,appMasterHost=N/A,startTime=1435039569909,finishTime=1435039573919,finalStatus=FAILED,memorySeconds=2564,vcoreSeconds=2,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType 2015-06-23 06:06:20,502 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001 2015-06-23 06:06:20,502 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001 2015-06-23 06:06:20,502 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED 2015-06-23 06:06:20,502 DEBUG [ Thread -693] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0001_000001 2015-06-23 06:06:20,502 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435039562888_0003 of type APP_COMPLETED 2015-06-23 06:06:20,502 INFO [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logSuccess(148)) - USER=user OPERATION=Application Finished - Killed TARGET=RMAppManager RESULT=SUCCESS APPID=application_1435039562888_0003 2015-06-23 06:06:20,503 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435039562888_0003_000001 2015-06-23 06:06:20,503 INFO [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435039562888_0003,name=name,user=user,queue= default ,state=KILLED,trackingUrl=http: //asf906.gq1.ygridcore.net:8088/proxy/application_1435039562888_0003/,appMasterHost=N/A,startTime=1435039574916,finishTime=1435039578925,finalStatus=KILLED,memorySeconds=6,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType 2015-06-23 06:06:20,508 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452)) - Service: ResourceManager entered state STOPPED From above logs, you can see RMAppManager processing event for application_1435039562888_0003 of type APP_COMPLETED is after all Verifying access-type VIEW_APP which is called from rm2.getClientRMService().getApplications . The corresponding logs from succeeded test: 2015-06-22 23:45:01,319 INFO [ Thread -1] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(572)) - Recovery started 2015-06-22 23:45:01,320 INFO [ Thread -1] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:recover(178)) - recovering RMDelegationTokenSecretManager. 2015-06-22 23:45:01,348 INFO [ Thread -1] resourcemanager.RMAppManager (RMAppManager.java:recover(425)) - Recovering 3 applications 2015-06-22 23:45:01,349 DEBUG [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435041883856_0001 of type RECOVER 2015-06-22 23:45:01,349 INFO [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435041883856_0001 with 1 attempts and final state = FINISHED 2015-06-22 23:45:01,350 INFO [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435041883856_0001_000001 with final state: FINISHED 2015-06-22 23:45:01,351 DEBUG [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435041883856_0001_000001 of type RECOVER 2015-06-22 23:45:01,351 INFO [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435041883856_0001_000001 State change from NEW to FINISHED 2015-06-22 23:45:01,351 INFO [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0001 State change from NEW to FINISHED 2015-06-22 23:45:01,352 DEBUG [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435041883856_0002 of type RECOVER 2015-06-22 23:45:01,352 INFO [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435041883856_0002 with 1 attempts and final state = FAILED 2015-06-22 23:45:01,353 INFO [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435041883856_0002_000001 with final state: FAILED 2015-06-22 23:45:01,353 DEBUG [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435041883856_0002_000001 of type RECOVER 2015-06-22 23:45:01,354 INFO [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435041883856_0002_000001 State change from NEW to FAILED 2015-06-22 23:45:01,354 INFO [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0002 State change from NEW to FAILED 2015-06-22 23:45:01,354 DEBUG [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:handle(756)) - Processing event for application_1435041883856_0003 of type RECOVER 2015-06-22 23:45:01,354 INFO [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:recover(781)) - Recovering app: application_1435041883856_0003 with 1 attempts and final state = KILLED 2015-06-22 23:45:01,355 INFO [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:recover(827)) - Recovering attempt: appattempt_1435041883856_0003_000001 with final state: KILLED 2015-06-22 23:45:01,356 DEBUG [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(781)) - Processing event for appattempt_1435041883856_0003_000001 of type RECOVER 2015-06-22 23:45:01,356 INFO [ Thread -1] attempt.RMAppAttemptImpl (RMAppAttemptImpl.java:handle(793)) - appattempt_1435041883856_0003_000001 State change from NEW to KILLED 2015-06-22 23:45:01,356 INFO [ Thread -1] rmapp.RMAppImpl (RMAppImpl.java:handle(768)) - application_1435041883856_0003 State change from NEW to KILLED 2015-06-22 23:45:01,356 INFO [ Thread -1] resourcemanager.ResourceManager (ResourceManager.java:serviceStart(579)) - Recovery ended 2015-06-22 23:45:01,356 DEBUG [ Thread -1] service.CompositeService (CompositeService.java:serviceStart(115)) - RMActiveServices: starting services, size=15 2015-06-22 23:45:01,356 INFO [ Thread -1] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(105)) - Rolling master-key for container-tokens 2015-06-22 23:45:01,356 INFO [ Thread -1] security.RMContainerTokenSecretManager (RMContainerTokenSecretManager.java:rollMasterKey(110)) - Going to activate master-key with key-id 344850257 in 900000ms 2015-06-22 23:45:01,357 INFO [ Thread -1] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(95)) - Rolling master-key for nm-tokens 2015-06-22 23:45:01,357 INFO [ Thread -1] security.NMTokenSecretManagerInRM (NMTokenSecretManagerInRM.java:rollMasterKey(100)) - Going to activate master-key with key-id -867844649 in 900000ms 2015-06-22 23:45:01,357 INFO [ Thread -1] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master key for generating delegation tokens 2015-06-22 23:45:01,357 INFO [ Thread -1] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID 3 2015-06-22 23:45:01,357 DEBUG [ Thread -1] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832)) - Processing event of type STORE_MASTERKEY 2015-06-22 23:45:01,357 INFO [ Thread -1] recovery.RMStateStore (RMStateStore.java:transition(365)) - Storing RMDTMasterKey. 2015-06-22 23:45:01,357 INFO [ Thread -1] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213)) - Store RMDT master key with key id: 3. Currently rmDTMasterKeyState size: 3 2015-06-22 23:45:01,358 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.RMSecretManagerService is started 2015-06-22 23:45:01,358 INFO [ Thread [ Thread -21,5,main]] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:run(649)) - Starting expired delegation token remover thread, tokenRemoverScanInterval=60 min(s) 2015-06-22 23:45:01,358 INFO [ Thread [ Thread -21,5,main]] delegation.AbstractDelegationTokenSecretManager (AbstractDelegationTokenSecretManager.java:updateCurrentKey(336)) - Updating the current master key for generating delegation tokens 2015-06-22 23:45:01,358 INFO [ Thread [ Thread -21,5,main]] security.RMDelegationTokenSecretManager (RMDelegationTokenSecretManager.java:storeNewMasterKey(87)) - storing master key with keyID 4 2015-06-22 23:45:01,358 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.rmcontainer.ContainerAllocationExpirer is started 2015-06-22 23:45:01,359 DEBUG [ Thread [ Thread -21,5,main]] recovery.RMStateStore (RMStateStore.java:handleStoreEvent(832)) - Processing event of type STORE_MASTERKEY 2015-06-22 23:45:01,359 INFO [ Thread [ Thread -21,5,main]] recovery.RMStateStore (RMStateStore.java:transition(365)) - Storing RMDTMasterKey. 2015-06-22 23:45:01,359 INFO [ Thread [ Thread -21,5,main]] recovery.RMStateStore (MemoryRMStateStore.java:storeRMDTMasterKeyState(213)) - Store RMDT master key with key id: 4. Currently rmDTMasterKeyState size: 4 2015-06-22 23:45:01,359 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service AMLivelinessMonitor is started 2015-06-22 23:45:01,359 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service AMLivelinessMonitor is started 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.nodelabels.CommonNodeLabelsManager is started 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter: starting services, size=0 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ahs.RMApplicationHistoryWriter is started 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher: starting services, size=0 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.metrics.SystemMetricsPublisher is started 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.NodesListManager is started 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.CapacityScheduler is started 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ResourceManager$SchedulerEventDispatcher is started 2015-06-22 23:45:01,360 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service NMLivelinessMonitor is started 2015-06-22 23:45:01,361 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ResourceTrackerService is started 2015-06-22 23:45:01,361 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ApplicationMasterService is started 2015-06-22 23:45:01,361 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.ClientRMService is started 2015-06-22 23:45:01,361 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.amlauncher.ApplicationMasterLauncher is started 2015-06-22 23:45:01,361 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service RMActiveServices is started 2015-06-22 23:45:01,361 INFO [ Thread -1] resourcemanager.ResourceManager (ResourceManager.java:transitionToActive(1049)) - Transitioned to active state 2015-06-22 23:45:01,361 DEBUG [ Thread -1] service.CompositeService (CompositeService.java:serviceStart(115)) - ResourceManager: starting services, size=2 2015-06-22 23:45:01,361 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service Dispatcher is started 2015-06-22 23:45:01,361 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED 2015-06-22 23:45:01,361 DEBUG [ Thread -1] service.CompositeService (CompositeService.java:serviceStart(115)) - org.apache.hadoop.yarn.server.resourcemanager.AdminService: starting services, size=0 2015-06-22 23:45:01,362 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service org.apache.hadoop.yarn.server.resourcemanager.AdminService is started 2015-06-22 23:45:01,362 DEBUG [ Thread -1] service.AbstractService (AbstractService.java:start(197)) - Service ResourceManager is started 2015-06-22 23:45:01,363 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0001 of type APP_COMPLETED 2015-06-22 23:45:01,363 INFO [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logSuccess(148)) - USER=user OPERATION=Application Finished - Succeeded TARGET=RMAppManager RESULT=SUCCESS APPID=application_1435041883856_0001 2015-06-22 23:45:01,363 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001 2015-06-22 23:45:01,364 INFO [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0001,name=name,user=user,queue= default ,state=FINISHED,trackingUrl=http: //zxu-mbp.local:8088/proxy/application_1435041883856_0001/,appMasterHost=N/A,startTime=1435041884030,finishTime=1435041888611,finalStatus=SUCCEEDED,memorySeconds=112,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType 2015-06-22 23:45:01,365 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED 2015-06-22 23:45:01,365 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0002 of type APP_COMPLETED 2015-06-22 23:45:01,365 WARN [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logFailure(263)) - USER=user OPERATION=Application Finished - Failed TARGET=RMAppManager RESULT=FAILURE DESCRIPTION=App failed with state: FAILED PERMISSIONS=Application application_1435041883856_0002 failed 1 times due to AM Container for appattempt_1435041883856_0002_000001 exited with exitCode: 0 Failing this attempt.Diagnostics: SuccessFor more detailed output, check the application tracking page: http: //zxu-mbp.local:8088/cluster/app/application_1435041883856_0002 Then click on links to logs of each attempt. . Failing the application. APPID=application_1435041883856_0002 2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001 2015-06-22 23:45:01,366 INFO [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0002,name=name,user=user,queue= default ,state=FAILED,trackingUrl=http: //zxu-mbp.local:8088/proxy/application_1435041883856_0002/,appMasterHost=N/A,startTime=1435041890627,finishTime=1435041894642,finalStatus=FAILED,memorySeconds=2565,vcoreSeconds=2,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType 2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] event.AsyncDispatcher (AsyncDispatcher.java:dispatch(167)) - Dispatching the event org.apache.hadoop.yarn.server.resourcemanager.RMAppManagerEvent.EventType: APP_COMPLETED 2015-06-22 23:45:01,366 DEBUG [AsyncDispatcher event handler] resourcemanager.RMAppManager (RMAppManager.java:handle(434)) - RMAppManager processing event for application_1435041883856_0003 of type APP_COMPLETED 2015-06-22 23:45:01,367 INFO [AsyncDispatcher event handler] resourcemanager.RMAuditLogger (RMAuditLogger.java:logSuccess(148)) - USER=user OPERATION=Application Finished - Killed TARGET=RMAppManager RESULT=SUCCESS APPID=application_1435041883856_0003 2015-06-22 23:45:01,367 DEBUG [AsyncDispatcher event handler] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001 2015-06-22 23:45:01,368 INFO [AsyncDispatcher event handler] resourcemanager.RMAppManager$ApplicationSummary (RMAppManager.java:logAppSummary(187)) - appId=application_1435041883856_0003,name=name,user=user,queue= default ,state=KILLED,trackingUrl=http: //zxu-mbp.local:8088/proxy/application_1435041883856_0003/,appMasterHost=N/A,startTime=1435041895640,finishTime=1435041899657,finalStatus=KILLED,memorySeconds=18,vcoreSeconds=0,preemptedAMContainers=0,preemptedNonAMContainers=0,preemptedResources=<memory:0\, vCores:0>,applicationType=myType 2015-06-22 23:45:01,368 DEBUG [ Thread -1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0001 owned by user 2015-06-22 23:45:01,370 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001 2015-06-22 23:45:01,370 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001 2015-06-22 23:45:01,370 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001 2015-06-22 23:45:01,376 DEBUG [ Thread -1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0002 owned by user 2015-06-22 23:45:01,377 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001 2015-06-22 23:45:01,377 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001 2015-06-22 23:45:01,377 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001 2015-06-22 23:45:01,378 DEBUG [ Thread -1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0003 owned by user 2015-06-22 23:45:01,378 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001 2015-06-22 23:45:01,379 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001 2015-06-22 23:45:01,379 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001 2015-06-22 23:45:01,382 DEBUG [ Thread -1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0001 owned by user 2015-06-22 23:45:01,384 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001 2015-06-22 23:45:01,384 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001 2015-06-22 23:45:01,384 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0001_000001 2015-06-22 23:45:01,384 DEBUG [ Thread -1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0002 owned by user 2015-06-22 23:45:01,386 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001 2015-06-22 23:45:01,386 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001 2015-06-22 23:45:01,386 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0002_000001 2015-06-22 23:45:01,386 DEBUG [ Thread -1] security.ApplicationACLsManager (ApplicationACLsManager.java:checkAccess(102)) - Verifying access-type VIEW_APP for zxu (auth:SIMPLE) on application application_1435041883856_0003 owned by user 2015-06-22 23:45:01,387 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001 2015-06-22 23:45:01,387 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001 2015-06-22 23:45:01,387 DEBUG [ Thread -1] scheduler.AbstractYarnScheduler (AbstractYarnScheduler.java:getAppResourceUsageReport(255)) - Request for appInfo of unknown attempt appattempt_1435041883856_0003_000001 2015-06-22 23:45:01,395 DEBUG [main] service.AbstractService (AbstractService.java:enterState(452)) - Service: ResourceManager entered state STOPPED From above logs, you can see RMAppManager processing event for application_1435041883856_0003 of type APP_COMPLETED is before Verifying access-type VIEW_APP.
          Hide
          xgong Xuan Gong added a comment -

          I saw the testcase failure with the same issue.
          rMAppManager.logApplicationSummary(
          isA(org.apache.hadoop.yarn.api.records.ApplicationId)
          );
          Wanted 3 times:
          -> at org.apache.hadoop.yarn.server.resourcemanager.TestRMRestart.testRMRestartGetApplicationList(TestRMRestart.java:969)
          But was 2 times:
          -> at org.apache.hadoop.yarn.server.resourcemanager.RMAppManager.handle(RMAppManager.java:66)
          Stacktrace

          org.mockito.exceptions.verification.TooLittleActualInvocations:
          rMAppManager.logApplicationSummary(
          isA(org.apache.hadoop.yarn.api.records.ApplicationId)
          );
          Wanted 3 times:
          -> at org.apache.hadoop.yarn.server.resourcemanager.TestRMRestart.testRMRestartGetApplicationList(TestRMRestart.java:969)
          But was 2 times:
          -> at org.apache.hadoop.yarn.server.resourcemanager.RMAppManager.handle(RMAppManager.java:66)

          at org.apache.hadoop.yarn.server.resourcemanager.TestRMRestart.testRMRestartGetApplicationList(TestRMRestart.java:969)

          Show
          xgong Xuan Gong added a comment - I saw the testcase failure with the same issue. rMAppManager.logApplicationSummary( isA(org.apache.hadoop.yarn.api.records.ApplicationId) ); Wanted 3 times: -> at org.apache.hadoop.yarn.server.resourcemanager.TestRMRestart.testRMRestartGetApplicationList(TestRMRestart.java:969) But was 2 times: -> at org.apache.hadoop.yarn.server.resourcemanager.RMAppManager.handle(RMAppManager.java:66) Stacktrace org.mockito.exceptions.verification.TooLittleActualInvocations: rMAppManager.logApplicationSummary( isA(org.apache.hadoop.yarn.api.records.ApplicationId) ); Wanted 3 times: -> at org.apache.hadoop.yarn.server.resourcemanager.TestRMRestart.testRMRestartGetApplicationList(TestRMRestart.java:969) But was 2 times: -> at org.apache.hadoop.yarn.server.resourcemanager.RMAppManager.handle(RMAppManager.java:66) at org.apache.hadoop.yarn.server.resourcemanager.TestRMRestart.testRMRestartGetApplicationList(TestRMRestart.java:969)

            People

            • Assignee:
              zxu zhihai xu
              Reporter:
              yuzhihong@gmail.com Ted Yu
            • Votes:
              0 Vote for this issue
              Watchers:
              9 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development