See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/868/changes
Changes: [ddas] HADOOP-2141. Improves the speculative execution heuristic. The heuristic is currently based on the progress-rates of tasks and the expected time to complete. Also, statistics about trackers are collected, and speculative tasks are not given to the ones deduced to be slow. Contributed by Andy Konwinski and Devaraj Das. [rangadi] HADOOP-6017. Lease Manager in NameNode does not handle certain characters in filenames. This results in fatal errors in Secondary NameNode and while restrating NameNode. (Tsz Wo (Nicholas), SZE via rangadi) [tomwhite] HADOOP-4041. IsolationRunner does not work as documented. Contributed by Philip Zeyliger. [shv] HADOOP-5897. Add name-node metrics to capture java heap usage. Contributed by Suresh Srinivas. ------------------------------------------ [...truncated 456472 lines...] [junit] 09/06/16 18:49:23 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000012_0 0.0% map > map [junit] 09/06/16 18:49:23 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000009_0 0.0% map > map [junit] 09/06/16 18:49:23 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000001_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:24 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000002_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:24 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:24 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000010_0 0.0% map > map [junit] 09/06/16 18:49:24 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000014_0 0.0% map > map [junit] 09/06/16 18:49:25 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000003_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:25 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000007_0 0.0% map > map [junit] 09/06/16 18:49:25 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000011_0 0.0% map > map [junit] 09/06/16 18:49:25 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:25 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000015_0 0.0% map > map [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000004_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000008_0 0.0% map > map [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000004_0 0.0% map > map [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000008_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000013_0 0.0% map > map [junit] 09/06/16 18:49:26 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000005_0 0.0% map > map [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000012_0 0.0% map > map [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000009_0 0.0% map > map [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000005_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:26 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000009_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:27 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000006_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:27 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:27 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000010_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:27 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000010_0 0.0% map > map [junit] 09/06/16 18:49:27 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000014_0 0.0% map > map [junit] 09/06/16 18:49:28 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000007_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:28 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000007_0 0.0% map > map [junit] 09/06/16 18:49:28 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000011_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:28 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000011_0 0.0% map > map [junit] 09/06/16 18:49:28 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:28 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000015_0 0.0% map > map [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000000_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000004_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000008_0 0.0% map > map [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000004_0 0.0% map > map [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000013_0 0.0% map > map [junit] 09/06/16 18:49:29 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000005_0 0.0% map > map [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000012_0 0.0% map > map [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000009_0 0.0% map > map [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000001_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:29 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000005_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:30 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000002_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:30 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000006_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:30 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:30 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000010_0 0.0% map > map [junit] 09/06/16 18:49:30 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000014_0 0.0% map > map [junit] 09/06/16 18:49:31 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000003_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:31 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000007_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:31 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000007_0 0.0% map > map [junit] 09/06/16 18:49:31 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000011_0 0.0% map > map [junit] 09/06/16 18:49:31 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:31 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000015_0 0.0% map > map [junit] 09/06/16 18:49:32 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000008_0 0.0% map > map [junit] 09/06/16 18:49:32 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000004_0 0.0% map > map [junit] 09/06/16 18:49:32 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000008_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:32 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000013_0 0.0% map > map [junit] 09/06/16 18:49:32 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:32 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000005_0 0.0% map > map [junit] 09/06/16 18:49:32 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000012_0 0.0% map > map [junit] 09/06/16 18:49:32 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000009_0 0.0% map > map [junit] 09/06/16 18:49:32 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000009_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:33 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:33 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000010_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:33 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000010_0 0.0% map > map [junit] 09/06/16 18:49:33 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000014_0 0.0% map > map [junit] 09/06/16 18:49:34 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000007_0 0.0% map > map [junit] 09/06/16 18:49:34 INFO mapred.TaskTracker: attempt_200906161834_0001_r_000011_0 0.083333336% reduce > copy (4 of 16 at 0.00 MB/s) > [junit] 09/06/16 18:49:34 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000011_0 0.0% map > map [junit] 09/06/16 18:49:34 INFO mapred.ClusterWithCapacityScheduler: Waiting till cluster reaches steady state. currentTasks : 11 total cluster capacity : 12 [junit] 09/06/16 18:49:34 INFO mapred.TaskTracker: attempt_200906161834_0001_m_000015_0 0.0% map > map [junit] Running org.apache.hadoop.mapred.TestQueueCapacities [junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0 sec [junit] Test org.apache.hadoop.mapred.TestQueueCapacities FAILED (timeout) checkfailure: [touch] Creating http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/testsfailed check-contrib: init: [echo] contrib: mrunit init-contrib: ivy-download: [get] Getting: http://repo2.maven.org/maven2/org/apache/ivy/ivy/2.0.0-rc2/ivy-2.0.0-rc2.jar [get] To: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivy-2.0.0-rc2.jar [get] Not modified - so not downloaded ivy-probe-antlib: ivy-init-antlib: ivy-init: :: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml ivy-resolve-common: [ivy:resolve] :: resolving dependencies :: org.apache.hadoop#mrunit;work...@vesta.apache.org [ivy:resolve] confs: [common] [ivy:resolve] found commons-logging#commons-logging;1.0.4 in maven2 [ivy:resolve] found log4j#log4j;1.2.15 in maven2 [ivy:resolve] found junit#junit;4.5 in maven2 [ivy:resolve] :: resolution report :: resolve 18ms :: artifacts dl 1ms --------------------------------------------------------------------- | | modules || artifacts | | conf | number| search|dwnlded|evicted|| number|dwnlded| --------------------------------------------------------------------- | common | 3 | 0 | 0 | 0 || 3 | 0 | --------------------------------------------------------------------- ivy-retrieve-common: [ivy:retrieve] :: retrieving :: org.apache.hadoop#mrunit [sync] [ivy:retrieve] confs: [common] [ivy:retrieve] 0 artifacts copied, 3 already retrieved (0kB/1ms) No ivy:settings found for the default reference 'ivy.instance'. A default instance will be used DEPRECATED: 'ivy.conf.file' is deprecated, use 'ivy.settings.file' instead :: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml compile: [echo] contrib: mrunit compile-examples: compile-test: [echo] contrib: mrunit [javac] Compiling 9 source files to http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test [javac] Note: Some input files use or override a deprecated API. [javac] Note: Recompile with -Xlint:deprecation for details. test: [echo] contrib: mrunit [delete] Deleting directory http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs [mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/mrunit/test/logs [junit] Running org.apache.hadoop.mrunit.TestExample [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.201 sec [junit] Running org.apache.hadoop.mrunit.TestMapDriver [junit] 09/06/16 18:49:36 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs. [junit] 09/06/16 18:49:36 ERROR mrunit.TestDriver: Received unexpected output (null, null) [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.204 sec [junit] Running org.apache.hadoop.mrunit.TestMapReduceDriver [junit] 09/06/16 18:49:37 ERROR mrunit.TestDriver: Missing expected output (foo, 52) at position 0 [junit] Tests run: 8, Failures: 0, Errors: 0, Time elapsed: 0.212 sec [junit] Running org.apache.hadoop.mrunit.TestReduceDriver [junit] 09/06/16 18:49:37 ERROR mrunit.TestDriver: Expected no outputs; got 1 outputs. [junit] 09/06/16 18:49:37 ERROR mrunit.TestDriver: Received unexpected output (null, 0) [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.208 sec [junit] Running org.apache.hadoop.mrunit.TestTestDriver [junit] Tests run: 19, Failures: 0, Errors: 0, Time elapsed: 0.2 sec [junit] Running org.apache.hadoop.mrunit.mock.TestMockReporter [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.104 sec [junit] Running org.apache.hadoop.mrunit.types.TestPair [junit] Tests run: 20, Failures: 0, Errors: 0, Time elapsed: 0.067 sec checkfailure: check-contrib: init: [echo] contrib: dynamic-priority init-contrib: ivy-download: [get] Getting: http://repo2.maven.org/maven2/org/apache/ivy/ivy/2.0.0-rc2/ivy-2.0.0-rc2.jar [get] To: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivy-2.0.0-rc2.jar [get] Not modified - so not downloaded ivy-probe-antlib: ivy-init-antlib: ivy-init: :: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml ivy-resolve-common: [ivy:resolve] :: resolving dependencies :: org.apache.hadoop#dynamic-priority;work...@vesta.apache.org [ivy:resolve] confs: [common] [ivy:resolve] found commons-logging#commons-logging;1.0.4 in maven2 [ivy:resolve] found log4j#log4j;1.2.15 in maven2 [ivy:resolve] found commons-httpclient#commons-httpclient;3.0.1 in maven2 [ivy:resolve] found commons-codec#commons-codec;1.3 in maven2 [ivy:resolve] found xmlenc#xmlenc;0.52 in maven2 [ivy:resolve] found net.java.dev.jets3t#jets3t;0.6.1 in maven2 [ivy:resolve] found commons-net#commons-net;1.4.1 in maven2 [ivy:resolve] found org.mortbay.jetty#servlet-api-2.5;6.1.14 in maven2 [ivy:resolve] found oro#oro;2.0.8 in maven2 [ivy:resolve] found org.mortbay.jetty#jetty;6.1.14 in maven2 [ivy:resolve] found org.mortbay.jetty#jetty-util;6.1.14 in maven2 [ivy:resolve] found tomcat#jasper-runtime;5.5.12 in maven2 [ivy:resolve] found tomcat#jasper-compiler;5.5.12 in maven2 [ivy:resolve] found commons-el#commons-el;1.0 in maven2 [ivy:resolve] found junit#junit;4.5 in maven2 [ivy:resolve] found commons-logging#commons-logging-api;1.0.4 in maven2 [ivy:resolve] found org.slf4j#slf4j-api;1.4.3 in maven2 [ivy:resolve] found org.slf4j#slf4j-log4j12;1.4.3 in maven2 [ivy:resolve] :: resolution report :: resolve 118ms :: artifacts dl 8ms --------------------------------------------------------------------- | | modules || artifacts | | conf | number| search|dwnlded|evicted|| number|dwnlded| --------------------------------------------------------------------- | common | 18 | 0 | 0 | 0 || 18 | 0 | --------------------------------------------------------------------- ivy-retrieve-common: [ivy:retrieve] :: retrieving :: org.apache.hadoop#dynamic-priority [sync] [ivy:retrieve] confs: [common] [ivy:retrieve] 0 artifacts copied, 18 already retrieved (0kB/4ms) No ivy:settings found for the default reference 'ivy.instance'. A default instance will be used DEPRECATED: 'ivy.conf.file' is deprecated, use 'ivy.settings.file' instead :: loading settings :: file = http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/ivy/ivysettings.xml compile: [echo] contrib: dynamic-priority compile-examples: compile-test: [echo] contrib: dynamic-priority [javac] Compiling 4 source files to http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/dynamic-priority/test [javac] Note: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/dynamic-scheduler/src/test/org/apache/hadoop/mapred/BaseSchedulerTest.java uses or overrides a deprecated API. [javac] Note: Recompile with -Xlint:deprecation for details. test: [echo] contrib: dynamic-priority [delete] Deleting directory http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/dynamic-priority/test/logs [mkdir] Created dir: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/dynamic-priority/test/logs [junit] 09/06/16 18:49:39 WARN conf.Configuration: DEPRECATED: hadoop-site.xml found in the classpath. Usage of hadoop-site.xml is deprecated. Instead use core-site.xml, mapred-site.xml and hdfs-site.xml to override properties of core-default.xml, mapred-default.xml and hdfs-default.xml respectively [junit] Running org.apache.hadoop.mapred.TestDynamicScheduler [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.176 sec [junit] 09/06/16 18:49:40 WARN conf.Configuration: DEPRECATED: hadoop-site.xml found in the classpath. Usage of hadoop-site.xml is deprecated. Instead use core-site.xml, mapred-site.xml and hdfs-site.xml to override properties of core-default.xml, mapred-default.xml and hdfs-default.xml respectively [junit] Running org.apache.hadoop.mapred.TestPriorityScheduler [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.165 sec checkfailure: BUILD FAILED http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1047: The following error occurred while executing this line: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1028: The following error occurred while executing this line: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build.xml :61: Tests failed! Total time: 259 minutes 32 seconds Publishing Javadoc Recording test results Recording fingerprints Publishing Clover coverage report...