Description
The testcase TestMRJobs#testJobClassloaderWithCustomClasses fails consistently with this error:
[INFO] ------------------------------------------------------- [INFO] T E S T S [INFO] ------------------------------------------------------- [INFO] Running org.apache.hadoop.mapreduce.v2.TestMRJobs [ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 54.325 s <<< FAILURE! - in org.apache.hadoop.mapreduce.v2.TestMRJobs [ERROR] testJobClassloaderWithCustomClasses(org.apache.hadoop.mapreduce.v2.TestMRJobs) Time elapsed: 10.531 s <<< FAILURE! java.lang.AssertionError: Job status: Application application_1517928628935_0001 failed 2 times due to AM Container for appattempt_1517928628935_0001_000002 exited with exitCode: 1 Failing this attempt.Diagnostics: [2018-02-06 15:50:38.688]Exception from container-launch. Container id: container_1517928628935_0001_02_000001 Exit code: 1 [2018-02-06 15:50:38.693]Container exited with a non-zero exit code 1. Error file: prelaunch.err. Last 4096 bytes of prelaunch.err : Last 4096 bytes of stderr : log4j:WARN No appenders could be found for logger (org.apache.hadoop.mapreduce.v2.app.MRAppMaster). log4j:WARN Please initialize the log4j system properly. log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info. [2018-02-06 15:50:38.694]Container exited with a non-zero exit code 1. Error file: prelaunch.err. Last 4096 bytes of prelaunch.err : Last 4096 bytes of stderr : log4j:WARN No appenders could be found for logger (org.apache.hadoop.mapreduce.v2.app.MRAppMaster). log4j:WARN Please initialize the log4j system properly. log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info. For more detailed output, check the application tracking page: http://ubuntu:46235/cluster/app/application_1517928628935_0001 Then click on links to logs of each attempt. . Failing the application. at org.junit.Assert.fail(Assert.java:88) at org.junit.Assert.assertTrue(Assert.java:41) at org.apache.hadoop.mapreduce.v2.TestMRJobs.testJobClassloader(TestMRJobs.java:529) at org.apache.hadoop.mapreduce.v2.TestMRJobs.testJobClassloaderWithCustomClasses(TestMRJobs.java:477) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.internal.runners.statements.FailOnTimeout$StatementThread.run(FailOnTimeout.java:74)
Today I found the offending commit with git bisect and this failure is caused by YARN-2185.
The application master fails because of the following error:
2018-02-05 17:15:18,530 DEBUG [main] org.apache.hadoop.util.ExitUtil: Exiting with status 1: org.apache.hadoop.yarn.exceptions.YarnRuntimeException: java.lang.RuntimeException: java.lang.reflect.InvocationTargetException 1: org.apache.hadoop.yarn.exceptions.YarnRuntimeException: java.lang.RuntimeException: java.lang.reflect.InvocationTargetException at org.apache.hadoop.util.ExitUtil.terminate(ExitUtil.java:265) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.main(MRAppMaster.java:1694) Caused by: org.apache.hadoop.yarn.exceptions.YarnRuntimeException: java.lang.RuntimeException: java.lang.reflect.InvocationTargetException at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$3.call(MRAppMaster.java:554) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$3.call(MRAppMaster.java:534) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.callWithJobClassLoader(MRAppMaster.java:1802) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.createOutputCommitter(MRAppMaster.java:534) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.serviceInit(MRAppMaster.java:311) at org.apache.hadoop.service.AbstractService.init(AbstractService.java:164) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$6.run(MRAppMaster.java:1760) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.Subject.doAs(Subject.java:422) at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1965) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.initAndStartAppMaster(MRAppMaster.java:1757) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster.main(MRAppMaster.java:1691) Caused by: java.lang.RuntimeException: java.lang.reflect.InvocationTargetException at org.apache.hadoop.util.ReflectionUtils.newInstance(ReflectionUtils.java:135) at org.apache.hadoop.mapreduce.v2.app.MRAppMaster$3.call(MRAppMaster.java:550) ... 11 more Caused by: java.lang.reflect.InvocationTargetException at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.apache.hadoop.util.ReflectionUtils.newInstance(ReflectionUtils.java:133) ... 12 more Caused by: java.lang.ExceptionInInitializerError: incorrect classloader used at org.apache.hadoop.mapreduce.v2.TestMRJobs$CustomOutputFormat.verifyClassLoader(TestMRJobs.java:551) at org.apache.hadoop.mapreduce.v2.TestMRJobs$CustomOutputFormat.<init>(TestMRJobs.java:535) ... 17 more
The test expects the class CustomOutputFormat to be loaded by ApplicationClassLoader. After YARN-2185 however, the class is loaded by the system classloader. This class was supposed to be loaded from job.jar but apparently is picked from a different place.