See https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-22-branch/21/
###################################################################################
########################## LAST 60 LINES OF THE CONSOLE
###########################
[...truncated 50028 lines...]
[junit] 2011-02-01 00:19:12,479 INFO mapreduce.Job
(Job.java:printTaskEvents(1200)) - Task Id :
attempt_20110201001752122_0003_m_000005_0, Status : SUCCEEDED
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:10,650
WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to
load native-hadoop library for your platform... using builtin-java classes
where applicable
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:10,863
INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with
processName=MAP, sessionId=
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:10,863
WARN conf.Configuration (Configuration.java:handleDeprecation(313)) -
user.name is deprecated. Instead, use mapreduce.job.user.name
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:10,932
WARN conf.Configuration (Configuration.java:handleDeprecation(313)) -
mapred.task.id is deprecated. Instead, use mapreduce.task.attempt.id
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,025
INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(65)) - setsid exited
with exit code 0
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,075
INFO mapred.Task (Task.java:initialize(523)) - Using ResourceCalculatorPlugin
: org.apache.hadoop.mapreduce.util.LinuxResourceCalculatorPlugin@2c35e
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,216
INFO mapred.MapTask (MapTask.java:runOldMapper(387)) - numReduceTasks: 1
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,235
INFO mapred.MapTask (MapTask.java:setEquator(1021)) - (EQUATOR) 0 kvi
2621436(10485744)
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,235
INFO mapred.MapTask (MapTask.java:<init>(819)) - mapreduce.task.io.sort.mb: 10
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,236
INFO mapred.MapTask (MapTask.java:<init>(820)) - soft limit at 8388608
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,236
INFO mapred.MapTask (MapTask.java:<init>(821)) - bufstart = 0; bufvoid =
10485760
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,236
INFO mapred.MapTask (MapTask.java:<init>(822)) - kvstart = 2621436; length =
655360
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,427
INFO mapred.MapTask (MapTask.java:flush(1283)) - Starting flush of map output
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,427
INFO mapred.MapTask (MapTask.java:flush(1302)) - Spilling map output
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,427
INFO mapred.MapTask (MapTask.java:flush(1303)) - bufstart = 0; bufend =
4212958; bufvoid = 10485760
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,427
INFO mapred.MapTask (MapTask.java:flush(1305)) - kvstart = 2621436(10485744);
kvend = 2605048(10420192); length = 16389/655360
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,603
INFO mapred.MapTask (MapTask.java:sortAndSpill(1489)) - Finished spill 0
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,607
INFO mapred.Task (Task.java:done(848)) -
Task:attempt_20110201001752122_0003_m_000005_0 is done. And is in the process
of commiting
[junit] attempt_20110201001752122_0003_m_000005_0: 2011-02-01 00:19:11,657
INFO mapred.Task (Task.java:sendDone(968)) - Task
'attempt_20110201001752122_0003_m_000005_0' done.
[junit] 2011-02-01 00:19:13,055 INFO mapred.TaskTracker
(TaskTracker.java:reportProgress(2655)) -
attempt_20110201001752122_0003_r_000000_0 0.19047621% reduce > copy(4 of 7 at
2.31 MB/s)
[junit] 2011-02-01 00:19:13,309 INFO mapred.TaskTracker
(TaskTracker.java:sendMapFile(3827)) - Sent out 4232866 bytes to reduce 0 from
map: attempt_20110201001752122_0003_m_000002_0 given 4232866/4232862
[junit] 2011-02-01 00:19:13,310 INFO mapred.TaskTracker
(TaskTracker.java:doGet(3693)) - Shuffled 1maps
(mapIds=attempt_20110201001752122_0003_m_000002_0) to reduce 0 in 108s
[junit] 2011-02-01 00:19:13,310 INFO TaskTracker.clienttrace
(TaskTracker.java:doGet(3698)) - src: 127.0.0.1:47675, dest: 127.0.0.1:34497,
maps: 1, op: MAPRED_SHUFFLE, reduceID: 0, duration: 108
[junit] 2011-02-01 00:19:13,698 INFO mapred.TaskTracker
(TaskTracker.java:sendMapFile(3827)) - Sent out 4229356 bytes to reduce 0 from
map: attempt_20110201001752122_0003_m_000005_0 given 4229356/4229352
[junit] 2011-02-01 00:19:13,699 INFO mapred.TaskTracker
(TaskTracker.java:doGet(3693)) - Shuffled 1maps
(mapIds=attempt_20110201001752122_0003_m_000005_0) to reduce 0 in 69s
[junit] 2011-02-01 00:19:13,699 INFO TaskTracker.clienttrace
(TaskTracker.java:doGet(3698)) - src: 127.0.0.1:49870, dest: 127.0.0.1:49076,
maps: 1, op: MAPRED_SHUFFLE, reduceID: 0, duration: 69
[junit] 2011-02-01 00:19:13,712 INFO mapreduce.Job
(Job.java:monitorAndPrintJob(1099)) - map 85% reduce 14%
[junit] 2011-02-01 00:19:13,948 INFO mapred.JvmManager
(JvmManager.java:<init>(459)) - In JvmRunner constructed JVM ID:
jvm_20110201001752122_0003_m_-805494038
[junit] 2011-02-01 00:19:13,948 INFO mapred.JvmManager
(JvmManager.java:spawnNewJvm(423)) - JVM Runner
jvm_20110201001752122_0003_m_-805494038 spawned.
[junit] 2011-02-01 00:19:13,949 INFO mapred.JvmManager
(JvmManager.java:runChild(484)) - JVM :
jvm_20110201001752122_0003_m_-1957341329 exited with exit code 0. Number of
tasks it ran: 1
[junit] 2011-02-01 00:19:14,016 INFO mapred.JvmManager
(JvmManager.java:runChild(484)) - JVM :
jvm_20110201001752122_0003_m_-1337968352 exited with exit code 0. Number of
tasks it ran: 1
[junit] 2011-02-01 00:19:14,644 INFO mapred.TaskTracker
(TaskTracker.java:getTask(3239)) - JVM with ID:
jvm_20110201001752122_0003_m_-805494038 given task:
attempt_20110201001752122_0003_m_000006_0
[junit] 2011-02-01 00:19:15,139 INFO FSNamesystem.audit
(FSNamesystem.java:logAuditEvent(148)) - ugi=hudson ip=/127.0.0.1
cmd=open
src=/tmp/hadoop-hudson/mapred/staging/hudson/.staging/job_20110201001752122_0003/job.split
dst=null perm=null
[junit] 2011-02-01 00:19:15,153 INFO DataNode.clienttrace
(BlockSender.java:sendBlock(498)) - src: /127.0.0.1:41020, dest:
/127.0.0.1:33687, bytes: 466, op: HDFS_READ, cliID:
DFSClient_attempt_20110201001752122_0003_m_000006_0, offset: 0, srvID:
DS-2061819061-127.0.1.1-41020-1296519471957, blockid:
blk_-3569370456802119029_1016, duration: 208791
[junit] 2011-02-01 00:19:15,435 INFO mapred.TaskTracker
(TaskTracker.java:reportProgress(2655)) -
attempt_20110201001752122_0003_m_000006_0 0.0%
[junit] 2011-02-01 00:19:15,657 INFO mapred.TaskTracker
(TaskTracker.java:reportProgress(2655)) -
attempt_20110201001752122_0003_m_000006_0 0.667% map > sort
[junit] 2011-02-01 00:19:15,658 INFO mapred.TaskTracker
(TaskTracker.java:reportDone(2736)) - Task
attempt_20110201001752122_0003_m_000006_0 is done.
[junit] 2011-02-01 00:19:15,658 INFO mapred.TaskTracker
(TaskTracker.java:reportDone(2737)) - reported output size for
attempt_20110201001752122_0003_m_000006_0 was 4228186
[junit] 2011-02-01 00:19:15,659 INFO mapred.TaskTracker
(TaskTracker.java:addFreeSlots(2222)) - addFreeSlot : current free slots : 2
[junit] 2011-02-01 00:19:15,771 WARN util.ProcessTree
(ProcessTree.java:sendSignal(134)) - Error executing shell command
org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 2011-02-01 00:19:15,771 INFO util.ProcessTree
(ProcessTree.java:sendSignal(137)) - Sending signal to all members of process
group -25392: SIGTERM. Exit code 1
Build timed out. Aborting
[junit] 2011-02-01 00:19:16,156 INFO mapred.TaskTracker
(TaskTracker.java:reportProgress(2655)) -
attempt_20110201001752122_0003_r_000000_0 0.2857143% reduce > copy(6 of 7 at
2.42 MB/s)
[junit] 2011-02-01 00:19:16,725 INFO mapreduce.Job
(Job.java:monitorAndPrintJob(1099)) - map 85% reduce 19%
[junit] 2011-02-01 00:19:16,863 INFO mapred.JvmManager
(JvmManager.java:runChild(484)) - JVM : jvm_20110201001752122_0003_m_-529436276
exited with exit code 0. Number of tasks it ran: 1
[junit] 2011-02-01 00:19:17,146 WARN util.ProcessTree
(ProcessTree.java:sendSignal(134)) - Error executing shell command
org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 2011-02-01 00:19:17,147 INFO util.ProcessTree
(ProcessTree.java:sendSignal(137)) - Sending signal to all members of process
group -24693: SIGTERM. Exit code 1
[FINDBUGS] Skipping publisher since build result is FAILURE
Publishing Javadoc
Archiving artifacts
Recording test results
Recording fingerprints
Publishing Clover coverage report...
No Clover report will be published due to a Build Failure
Email was triggered for: Failure
Sending email for trigger: Failure
###################################################################################
############################## FAILED TESTS (if any)
##############################
1 tests failed.
FAILED: TEST-org.apache.hadoop.mapred.TestReduceFetch.xml.<init>
Error Message:
Stack Trace:
Test report file
/grid/0/hudson/hudson-slave/workspace/Hadoop-Mapreduce-22-branch/trunk/build/test/TEST-org.apache.hadoop.mapred.TestReduceFetch.xml
was length 0