See
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/520/changes>
Changes:
[dhruba] MAPREDUCE-2146. Raid does not affect access time of a source file.
(Ramkumar Vadali via dhruba)
------------------------------------------
[...truncated 33877 lines...]
[junit] 2010-10-27 05:59:42,112 INFO mapred.TaskTracker
(TaskTracker.java:reportProgress(2656)) -
attempt_20101027055837979_0002_r_000000_0 0.0% 1 / 1 copied.
[junit] 2010-10-27 05:59:42,410 INFO mapreduce.Job
(Job.java:monitorAndPrintJob(1099)) - map 100% reduce 0%
[junit] 2010-10-27 05:59:43,564 INFO mapred.TaskTracker
(TaskTracker.java:offerService(1542)) - Received commit task action for
attempt_20101027055837979_0002_r_000000_0
[junit] 2010-10-27 05:59:44,065 INFO mapred.JvmManager
(JvmManager.java:runChild(472)) - JVM :
jvm_20101027055837979_0002_m_-1397308071 exited with exit code 0. Number of
tasks it ran: 1
[junit] 2010-10-27 05:59:44,152 INFO mapred.TaskTracker
(TaskTracker.java:reportProgress(2656)) -
attempt_20101027055837979_0002_r_000000_0 1.0% reduce > reduce
[junit] 2010-10-27 05:59:44,153 INFO mapred.TaskTracker
(TaskTracker.java:reportDone(2737)) - Task
attempt_20101027055837979_0002_r_000000_0 is done.
[junit] 2010-10-27 05:59:44,154 INFO mapred.TaskTracker
(TaskTracker.java:reportDone(2738)) - reported output size for
attempt_20101027055837979_0002_r_000000_0 was -1
[junit] 2010-10-27 05:59:44,155 INFO mapred.TaskTracker
(TaskTracker.java:addFreeSlots(2223)) - addFreeSlot : current free slots : 2
[junit] 2010-10-27 05:59:44,328 WARN util.ProcessTree
(ProcessTree.java:sendSignal(134)) - Error executing shell command
org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 2010-10-27 05:59:44,329 INFO util.ProcessTree
(ProcessTree.java:sendSignal(137)) - Sending signal to all members of process
group -18537: SIGTERM. Exit code 1
[junit] 2010-10-27 05:59:46,570 INFO mapred.JobInProgress
(JobInProgress.java:completedTask(2636)) - Task
'attempt_20101027055837979_0002_r_000000_0' has completed
task_20101027055837979_0002_r_000000 successfully.
[junit] 2010-10-27 05:59:46,573 INFO mapred.JobTracker
(JobTracker.java:createTaskEntry(1828)) - Adding task (JOB_CLEANUP)
'attempt_20101027055837979_0002_m_000001_0' to tip
task_20101027055837979_0002_m_000001, for tracker
'tracker_host0.foo.com:localhost/127.0.0.1:50030'
[junit] 2010-10-27 05:59:46,575 INFO mapred.TaskTracker
(TaskTracker.java:registerTask(2315)) - LaunchTaskAction (registerTask):
attempt_20101027055837979_0002_m_000001_0 task's state:UNASSIGNED
[junit] 2010-10-27 05:59:46,575 INFO mapred.TaskTracker
(TaskTracker.java:run(2252)) - Trying to launch :
attempt_20101027055837979_0002_m_000001_0 which needs 1 slots
[junit] 2010-10-27 05:59:46,575 INFO mapred.TaskTracker
(TaskTracker.java:run(2284)) - In TaskLauncher, current free slots : 2 and
trying to launch attempt_20101027055837979_0002_m_000001_0 which needs 1 slots
[junit] 2010-10-27 05:59:46,576 INFO tasktracker.Localizer
(Localizer.java:initializeUserDirs(198)) - User-directories for the user hudson
are already initialized on this TT. Not doing anything.
[junit] 2010-10-27 05:59:46,577 INFO mapred.TaskTracker
(TaskTracker.java:processKillTaskAction(426)) - Received KillTaskAction for
task: attempt_20101027055837979_0002_r_000000_0
[junit] 2010-10-27 05:59:46,577 INFO mapred.TaskTracker
(TaskTracker.java:purgeTask(2041)) - About to purge task:
attempt_20101027055837979_0002_r_000000_0
[junit] 2010-10-27 05:59:46,633 INFO mapred.JvmManager
(JvmManager.java:<init>(445)) - In JvmRunner constructed JVM ID:
jvm_20101027055837979_0002_m_625172872
[junit] 2010-10-27 05:59:46,634 INFO mapred.JvmManager
(JvmManager.java:spawnNewJvm(413)) - JVM Runner
jvm_20101027055837979_0002_m_625172872 spawned.
[junit] 2010-10-27 05:59:47,379 INFO mapred.TaskTracker
(TaskTracker.java:getTask(3224)) - JVM with ID:
jvm_20101027055837979_0002_m_625172872 given task:
attempt_20101027055837979_0002_m_000001_0
[junit] 2010-10-27 05:59:47,421 INFO mapreduce.Job
(Job.java:printTaskEvents(1200)) - Task Id :
attempt_20101027055837979_0002_r_000000_0, Status : SUCCEEDED
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,565
INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with
processName=SHUFFLE, sessionId=
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,568
WARN conf.Configuration (Configuration.java:handleDeprecation(313)) -
user.name is deprecated. Instead, use mapreduce.job.user.name
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,597
INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(65)) - setsid exited
with exit code 0
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,609
INFO mapred.Task (Task.java:initialize(515)) - Using ResourceCalculatorPlugin
: org.apache.hadoop.mapreduce.util.linuxresourcecalculatorplu...@1687e7c
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,689
INFO reduce.MergeManager (MergeManager.java:<init>(178)) - MergerManager:
memoryLimit=141387360, maxSingleShuffleLimit=35346840, mergeThreshold=93315664,
ioSortFactor=10, memToMemMergeOutputsThreshold=10
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,696
INFO reduce.EventFetcher (EventFetcher.java:run(61)) -
attempt_20101027055837979_0002_r_000000_0 Thread started: EventFetcher for
fetching Map Completion Events
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,710
INFO reduce.ShuffleScheduler (ShuffleScheduler.java:getHost(303)) - Assiging
localhost:38334 with 1 to fetcher#3
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,710
INFO reduce.ShuffleScheduler (ShuffleScheduler.java:getMapsForHost(333)) -
assigned 1 of 1 to localhost:38334 to fetcher#3
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,719
INFO reduce.EventFetcher (EventFetcher.java:run(69)) -
attempt_20101027055837979_0002_r_000000_0: Got 1 new map-outputs
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,990
INFO reduce.Fetcher (Fetcher.java:copyFromHost(217)) - for
url=38334/mapOutput?job=job_20101027055837979_0002&reduce=0&map=attempt_20101027055837979_0002_m_000000_0
sent hash and receievd reply
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,993
INFO reduce.Fetcher (Fetcher.java:copyMapOutput(314)) - fetcher#3 about to
shuffle output of map attempt_20101027055837979_0002_m_000000_0 decomp: 107
len: 111 to MEMORY
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,995
INFO reduce.Fetcher (Fetcher.java:shuffleToMemory(479)) - Read 107 bytes from
map-output for attempt_20101027055837979_0002_m_000000_0
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,995
INFO reduce.MergeManager (MergeManager.java:closeInMemoryFile(277)) -
closeInMemoryFile -> map-output of size: 107, inMemoryMapOutputs.size() -> 1
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,997
INFO reduce.ShuffleScheduler (ShuffleScheduler.java:freeHost(345)) -
localhost:38334 freed by fetcher#3 in 287s
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,000
INFO reduce.MergeManager (MergeManager.java:finalMerge(629)) - finalMerge
called with 1 in-memory map-outputs and 0 on-disk map-outputs
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,024
INFO mapred.Merger (Merger.java:merge(549)) - Merging 1 sorted segments
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,024
INFO mapred.Merger (Merger.java:merge(648)) - Down to the last merge-pass,
with 1 segments left of total size: 103 bytes
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,034
INFO reduce.MergeManager (MergeManager.java:finalMerge(701)) - Merged 1
segments, 107 bytes to disk to satisfy reduce memory limit
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,035
INFO reduce.MergeManager (MergeManager.java:finalMerge(727)) - Merging 1
files, 111 bytes from disk
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,036
INFO reduce.MergeManager (MergeManager.java:finalMerge(742)) - Merging 0
segments, 0 bytes from memory into reduce
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,036
INFO mapred.Merger (Merger.java:merge(549)) - Merging 1 sorted segments
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,039
INFO mapred.Merger (Merger.java:merge(648)) - Down to the last merge-pass,
with 1 segments left of total size: 103 bytes
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,055
WARN conf.Configuration (Configuration.java:set(582)) - mapred.skip.on is
deprecated. Instead, use mapreduce.job.skiprecords
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:42,071
INFO mapred.Task (Task.java:done(840)) -
Task:attempt_20101027055837979_0002_r_000000_0 is done. And is in the process
of commiting
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:44,115
INFO mapred.Task (Task.java:commit(1001)) - Task
attempt_20101027055837979_0002_r_000000_0 is allowed to commit now
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:44,119
INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(173)) -
Saved output of task 'attempt_20101027055837979_0002_r_000000_0' to
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/data/out>
[junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:44,154
INFO mapred.Task (Task.java:sendDone(960)) - Task
'attempt_20101027055837979_0002_r_000000_0' done.
[junit] 2010-10-27 05:59:47,699 INFO mapred.TaskTracker
(TaskTracker.java:reportProgress(2656)) -
attempt_20101027055837979_0002_m_000001_0 0.0%
[junit] 2010-10-27 05:59:47,781 INFO mapred.TaskTracker
(TaskTracker.java:reportProgress(2656)) -
attempt_20101027055837979_0002_m_000001_0 0.0% cleanup > map
[junit] 2010-10-27 05:59:47,783 INFO mapred.TaskTracker
(TaskTracker.java:reportDone(2737)) - Task
attempt_20101027055837979_0002_m_000001_0 is done.
[junit] 2010-10-27 05:59:47,783 INFO mapred.TaskTracker
(TaskTracker.java:reportDone(2738)) - reported output size for
attempt_20101027055837979_0002_m_000001_0 was -1
[junit] 2010-10-27 05:59:47,784 INFO mapred.TaskTracker
(TaskTracker.java:addFreeSlots(2223)) - addFreeSlot : current free slots : 2
[junit] 2010-10-27 05:59:47,933 WARN util.ProcessTree
(ProcessTree.java:sendSignal(134)) - Error executing shell command
org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 2010-10-27 05:59:47,934 INFO util.ProcessTree
(ProcessTree.java:sendSignal(137)) - Sending signal to all members of process
group -18613: SIGTERM. Exit code 1
[junit] 2010-10-27 05:59:48,429 INFO mapreduce.Job
(Job.java:monitorAndPrintJob(1099)) - map 100% reduce 100%
[junit] 2010-10-27 05:59:49,347 INFO mapred.JvmManager
(JvmManager.java:runChild(472)) - JVM :
jvm_20101027055837979_0002_r_-2097158763 exited with exit code 0. Number of
tasks it ran: 1
[junit] 2010-10-27 05:59:49,580 INFO mapred.JobInProgress
(JobInProgress.java:completedTask(2636)) - Task
'attempt_20101027055837979_0002_m_000001_0' has completed
task_20101027055837979_0002_m_000001 successfully.
[junit] 2010-10-27 05:59:49,582 INFO mapred.JobInProgress
(JobInProgress.java:jobComplete(2837)) - Job job_20101027055837979_0002 has
completed successfully.
[junit] 2010-10-27 05:59:49,583 INFO mapred.JobInProgress$JobSummary
(JobInProgress.java:logJobSummary(3611)) -
jobId=job_20101027055837979_0002,submitTime=1288159173174,launchTime=1288159173441,firstMapTaskLaunchTime=1288159177545,firstReduceTaskLaunchTime=1288159180556,firstJobSetupTaskLaunchTime=1288159174529,firstJobCleanupTaskLaunchTime=1288159186573,finishTime=1288159189582,numMaps=1,numSlotsPerMap=1,numReduces=1,numSlotsPerReduce=1,user=hudson,queue=default,status=SUCCEEDED,mapSlotSeconds=3,reduceSlotsSeconds=3,clusterMapCapacity=4,clusterReduceCapacity=4
[junit] 2010-10-27 05:59:49,588 INFO jobhistory.JobHistory
(JobHistory.java:moveToDoneNow(354)) - Moving
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/history/job_20101027055837979_0002_hudson>
to
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/history/done/job_20101027055837979_0002_hudson>
[junit] 2010-10-27 05:59:49,589 INFO mapred.JobTracker
(JobTracker.java:removeTaskEntry(1863)) - Removing task
'attempt_20101027055837979_0002_m_000000_0'
[junit] 2010-10-27 05:59:49,590 INFO mapred.JobTracker
(JobTracker.java:removeTaskEntry(1863)) - Removing task
'attempt_20101027055837979_0002_m_000001_0'
[junit] 2010-10-27 05:59:49,590 INFO mapred.JobTracker
(JobTracker.java:removeTaskEntry(1863)) - Removing task
'attempt_20101027055837979_0002_m_000002_0'
[junit] 2010-10-27 05:59:49,590 INFO mapred.JobTracker
(JobTracker.java:removeTaskEntry(1863)) - Removing task
'attempt_20101027055837979_0002_r_000000_0'
[junit] 2010-10-27 05:59:49,592 INFO mapred.TaskTracker
(TaskTracker.java:purgeJob(1972)) - Received 'KillJobAction' for job:
job_20101027055837979_0002
[junit] 2010-10-27 05:59:49,602 INFO mapred.IndexCache
(IndexCache.java:removeMap(141)) - Map ID
attempt_20101027055837979_0002_m_000001_0 not found in cache
[junit] 2010-10-27 05:59:49,603 INFO mapred.UserLogCleaner
(UserLogCleaner.java:markJobLogsForDeletion(174)) - Adding
job_20101027055837979_0002 for user-log deletion with
retainTimeStamp:1288245589602
[junit] 2010-10-27 05:59:49,636 INFO jobhistory.JobHistory
(JobHistory.java:moveToDoneNow(354)) - Moving
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/history/job_20101027055837979_0002_conf.xml>
to
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/history/done/job_20101027055837979_0002_conf.xml>
[junit] 2010-10-27 05:59:49,664 INFO mapred.TaskTracker
(TaskTracker.java:purgeJob(1972)) - Received 'KillJobAction' for job:
job_20101027055837979_0002
[junit] 2010-10-27 05:59:49,665 WARN mapred.TaskTracker
(TaskTracker.java:purgeJob(1979)) - Unknown job job_20101027055837979_0002
being deleted.
[junit] 2010-10-27 05:59:49,690 INFO mapred.JobInProgress
(JobInProgress.java:cleanupLocalizedJobConf(3652)) - Deleting localized job
conf at
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/job_20101027055837979_0002_conf.xml>
[junit] 2010-10-27 05:59:50,436 INFO mapreduce.Job
(Job.java:printTaskEvents(1200)) - Task Id :
attempt_20101027055837979_0002_m_000001_0, Status : SUCCEEDED
[junit] attempt_20101027055837979_0002_m_000001_0: 2010-10-27 05:59:47,592
INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with
processName=MAP, sessionId=
[junit] attempt_20101027055837979_0002_m_000001_0: 2010-10-27 05:59:47,594
WARN conf.Configuration (Configuration.java:handleDeprecation(313)) -
user.name is deprecated. Instead, use mapreduce.job.user.name
[junit] attempt_20101027055837979_0002_m_000001_0: 2010-10-27 05:59:47,624
INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(65)) - setsid exited
with exit code 0
[junit] attempt_20101027055837979_0002_m_000001_0: 2010-10-27 05:59:47,639
INFO mapred.Task (Task.java:initialize(515)) - Using ResourceCalculatorPlugin
: org.apache.hadoop.mapreduce.util.linuxresourcecalculatorplu...@7a5a19
[junit] attempt_20101027055837979_0002_m_000001_0: 2010-10-27 05:59:47,700
INFO mapred.Task (Task.java:runJobCleanupTask(1049)) - Cleaning up job
[junit] attempt_20101027055837979_0002_m_000001_0: 2010-10-27 05:59:47,700
INFO mapred.Task (Task.java:runJobCleanupTask(1061)) - Committing job
[junit] attempt_20101027055837979_0002_m_000001_0: 2010-10-27 05:59:47,714
INFO mapred.Task (Task.java:done(840)) -
Task:attempt_20101027055837979_0002_m_000001_0 is done. And is in the process
of commiting
[junit] attempt_20101027055837979_0002_m_000001_0: 2010-10-27 05:59:47,783
INFO mapred.Task (Task.java:sendDone(960)) - Task
'attempt_20101027055837979_0002_m_000001_0' done.
[junit] 2010-10-27 05:59:50,442 INFO mapreduce.Job
(Job.java:monitorAndPrintJob(1108)) - Job complete: job_20101027055837979_0002
[junit] 2010-10-27 05:59:50,443 INFO mapred.AuditLogger
(AuditLogger.java:logSuccess(84)) - USER=hudson IP=127.0.0.1
OPERATION=VIEW_JOB_COUNTERS TARGET=job_20101027055837979_0002 in queue
default RESULT=SUCCESS
[junit] 2010-10-27 05:59:50,448 INFO mapreduce.Job
(Job.java:monitorAndPrintJob(1111)) - Counters: 33
[junit] FileSystemCounters
[junit] FILE_BYTES_READ=518
[junit] FILE_BYTES_WRITTEN=331
[junit] Shuffle Errors
[junit] BAD_ID=0
[junit] CONNECTION=0
[junit] IO_ERROR=0
[junit] WRONG_LENGTH=0
[junit] WRONG_MAP=0
[junit] WRONG_REDUCE=0
[junit] Job Counters
[junit] Total time spent by all maps waiting after reserving
slots (ms)=0
[junit] Total time spent by all reduces waiting after reserving
slots (ms)=0
[junit] Rack-local map tasks=1
[junit] SLOTS_MILLIS_MAPS=3639
[junit] SLOTS_MILLIS_REDUCES=3591
[junit] Launched map tasks=1
[junit] Launched reduce tasks=1
[junit] Map-Reduce Framework
[junit] Combine input records=13
[junit] Combine output records=10
[junit] CPU_MILLISECONDS=1360
[junit] Failed Shuffles=0
[junit] GC time elapsed (ms)=20
[junit] Map input records=4
[junit] Map output bytes=112
[junit] Map output records=13
[junit] Merged Map outputs=1
[junit] PHYSICAL_MEMORY_BYTES=101658624
[junit] Reduce input groups=10
[junit] Reduce input records=10
[junit] Reduce output records=10
[junit] Reduce shuffle bytes=111
[junit] Shuffled Maps =1
[junit] Spilled Records=20
[junit] SPLIT_RAW_BYTES=305
[junit] VIRTUAL_MEMORY_BYTES=740134912
[junit] a 1
[junit] count 1
[junit] file 1
[junit] is 1
[junit] more 1
[junit] multi 1
[junit] of 1
[junit] test 4
[junit] this 1
[junit] word 1
[junit]
[junit] 2010-10-27 05:59:50,454 INFO util.AsyncDiskService
(AsyncDiskService.java:shutdown(111)) - Shutting down all AsyncDiskService
threads...
[junit] 2010-10-27 05:59:50,456 INFO util.AsyncDiskService
(AsyncDiskService.java:awaitTermination(140)) - All AsyncDiskService threads
are terminated.
[junit] 2010-10-27 05:59:50,456 INFO mapred.TaskTracker
(TaskTracker.java:run(865)) - Shutting down: Map-events fetcher for all reduce
tasks on tracker_host0.foo.com:localhost/127.0.0.1:50030
[junit] 2010-10-27 05:59:50,462 ERROR
filecache.TrackerDistributedCacheManager
(TrackerDistributedCacheManager.java:run(935)) - Exception in DistributedCache
CleanupThread.
[junit] java.lang.InterruptedException: sleep interrupted
[junit] at java.lang.Thread.sleep(Native Method)
[junit] at
org.apache.hadoop.mapreduce.filecache.TrackerDistributedCacheManager$CleanupThread.run(TrackerDistributedCacheManager.java:932)
[junit] 2010-10-27 05:59:52,951 INFO mapred.JvmManager
(JvmManager.java:runChild(472)) - JVM : jvm_20101027055837979_0002_m_625172872
exited with exit code 0. Number of tasks it ran: 1
[junit] 2010-10-27 05:59:52,951 INFO ipc.Server (Server.java:stop(1601)) -
Stopping server on 50030
[junit] 2010-10-27 05:59:52,952 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 0 on 50030: exiting
[junit] 2010-10-27 05:59:52,952 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 2 on 50030: exiting
[junit] 2010-10-27 05:59:52,952 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 3 on 50030: exiting
[junit] 2010-10-27 05:59:52,952 INFO ipc.Server (Server.java:run(475)) -
Stopping IPC Server listener on 50030
[junit] 2010-10-27 05:59:52,953 INFO mapred.TaskTracker
(TaskTracker.java:shutdown(1256)) - Shutting down StatusHttpServer
[junit] 2010-10-27 05:59:52,953 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 1 on 50030: exiting
[junit] 2010-10-27 05:59:52,953 INFO ipc.Server (Server.java:run(675)) -
Stopping IPC Server Responder
[junit] 2010-10-27 05:59:53,061 ERROR mapred.TaskTracker
(TaskTracker.java:offerService(1584)) - Caught exception: java.io.IOException:
Call to localhost/127.0.0.1:59636 failed on local exception:
java.nio.channels.ClosedByInterruptException
[junit] at org.apache.hadoop.ipc.Client.wrapException(Client.java:1063)
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:1031)
[junit] at
org.apache.hadoop.ipc.WritableRpcEngine$Invoker.invoke(WritableRpcEngine.java:198)
[junit] at org.apache.hadoop.mapred.$Proxy1.heartbeat(Unknown Source)
[junit] at
org.apache.hadoop.mapred.TaskTracker.transmitHeartBeat(TaskTracker.java:1684)
[junit] at
org.apache.hadoop.mapred.TaskTracker.offerService(TaskTracker.java:1515)
[junit] at
org.apache.hadoop.mapred.TaskTracker.run(TaskTracker.java:2420)
[junit] at
org.apache.hadoop.mapred.MiniMRCluster$TaskTrackerRunner.run(MiniMRCluster.java:228)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit] Caused by: java.nio.channels.ClosedByInterruptException
[junit] at
java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184)
[junit] at
sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:341)
[junit] at
org.apache.hadoop.net.SocketOutputStream$Writer.performIO(SocketOutputStream.java:60)
[junit] at
org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:142)
[junit] at
org.apache.hadoop.net.SocketOutputStream.write(SocketOutputStream.java:151)
[junit] at
org.apache.hadoop.net.SocketOutputStream.write(SocketOutputStream.java:112)
[junit] at
java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
[junit] at
java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
[junit] at java.io.DataOutputStream.flush(DataOutputStream.java:106)
[junit] at
org.apache.hadoop.ipc.Client$Connection.sendParam(Client.java:739)
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:1009)
[junit] ... 7 more
[junit]
[junit] 2010-10-27 05:59:53,063 INFO util.AsyncDiskService
(AsyncDiskService.java:shutdown(111)) - Shutting down all AsyncDiskService
threads...
[junit] 2010-10-27 05:59:53,063 INFO util.AsyncDiskService
(AsyncDiskService.java:awaitTermination(140)) - All AsyncDiskService threads
are terminated.
[junit] 2010-10-27 05:59:53,066 INFO util.AsyncDiskService
(AsyncDiskService.java:shutdown(111)) - Shutting down all AsyncDiskService
threads...
[junit] 2010-10-27 05:59:53,067 INFO util.AsyncDiskService
(AsyncDiskService.java:awaitTermination(140)) - All AsyncDiskService threads
are terminated.
[junit] 2010-10-27 05:59:53,068 INFO mapred.TaskTracker
(TaskTracker.java:run(865)) - Shutting down: Map-events fetcher for all reduce
tasks on tracker_host1.foo.com:localhost/127.0.0.1:50579
[junit] 2010-10-27 05:59:53,068 ERROR
filecache.TrackerDistributedCacheManager
(TrackerDistributedCacheManager.java:run(935)) - Exception in DistributedCache
CleanupThread.
[junit] java.lang.InterruptedException: sleep interrupted
[junit] at java.lang.Thread.sleep(Native Method)
[junit] at
org.apache.hadoop.mapreduce.filecache.TrackerDistributedCacheManager$CleanupThread.run(TrackerDistributedCacheManager.java:932)
[junit] 2010-10-27 05:59:53,068 INFO ipc.Server (Server.java:stop(1601)) -
Stopping server on 50579
[junit] 2010-10-27 05:59:53,068 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 2 on 50579: exiting
[junit] 2010-10-27 05:59:53,069 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 0 on 50579: exiting
[junit] 2010-10-27 05:59:53,069 INFO mapred.TaskTracker
(TaskTracker.java:shutdown(1256)) - Shutting down StatusHttpServer
[junit] 2010-10-27 05:59:53,069 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 1 on 50579: exiting
[junit] 2010-10-27 05:59:53,069 INFO ipc.Server (Server.java:run(475)) -
Stopping IPC Server listener on 50579
[junit] 2010-10-27 05:59:53,069 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 3 on 50579: exiting
[junit] 2010-10-27 05:59:53,069 INFO ipc.Server (Server.java:run(675)) -
Stopping IPC Server Responder
[junit] 2010-10-27 05:59:53,171 INFO mapred.TaskTracker
(TaskTracker.java:offerService(1564)) - Interrupted. Closing down.
[junit] 2010-10-27 05:59:53,172 INFO util.AsyncDiskService
(AsyncDiskService.java:shutdown(111)) - Shutting down all AsyncDiskService
threads...
[junit] 2010-10-27 05:59:53,172 INFO util.AsyncDiskService
(AsyncDiskService.java:awaitTermination(140)) - All AsyncDiskService threads
are terminated.
[junit] 2010-10-27 05:59:53,173 INFO mapred.JobTracker
(JobTracker.java:close(1765)) - Stopping infoServer
[junit] 2010-10-27 05:59:53,275 INFO mapred.JobTracker
(JobTracker.java:close(1773)) - Stopping interTrackerServer
[junit] 2010-10-27 05:59:53,275 INFO ipc.Server (Server.java:stop(1601)) -
Stopping server on 59636
[junit] 2010-10-27 05:59:53,275 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 1 on 59636: exiting
[junit] 2010-10-27 05:59:53,275 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 2 on 59636: exiting
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(475)) -
Stopping IPC Server listener on 59636
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 6 on 59636: exiting
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(675)) -
Stopping IPC Server Responder
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 9 on 59636: exiting
[junit] 2010-10-27 05:59:53,276 INFO mapred.JobTracker
(JobTracker.java:stopExpireTrackersThread(1812)) - Stopping expireTrackers
[junit] 2010-10-27 05:59:53,275 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 0 on 59636: exiting
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 3 on 59636: exiting
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 4 on 59636: exiting
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 8 on 59636: exiting
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 5 on 59636: exiting
[junit] 2010-10-27 05:59:53,276 INFO mapred.JobTracker
(JobTracker.java:offerService(1760)) - Stopped interTrackerServer
[junit] 2010-10-27 05:59:53,276 INFO ipc.Server (Server.java:run(1444)) -
IPC Server handler 7 on 59636: exiting
[junit] 2010-10-27 05:59:53,277 INFO
mapred.EagerTaskInitializationListener
(EagerTaskInitializationListener.java:terminate(108)) - Stopping Job Init
Manager thread
[junit] 2010-10-27 05:59:53,278 INFO
mapred.EagerTaskInitializationListener
(EagerTaskInitializationListener.java:run(61)) - JobInitManagerThread
interrupted.
[junit] 2010-10-27 05:59:53,278 INFO
mapred.EagerTaskInitializationListener
(EagerTaskInitializationListener.java:run(65)) - Shutting down thread pool
[junit] 2010-10-27 05:59:53,278 INFO mapred.JobTracker
(JobTracker.java:close(1783)) - Stopping expireLaunchingTasks
[junit] 2010-10-27 05:59:53,279 INFO jobhistory.JobHistory
(JobHistory.java:shutDown(195)) - Interrupting History Cleaner
[junit] 2010-10-27 05:59:53,279 INFO jobhistory.JobHistory
(JobHistory.java:run(544)) - History Cleaner thread exiting
[junit] 2010-10-27 05:59:53,279 INFO mapred.JobTracker
(JobTracker.java:close(1806)) - stopped all jobtracker services
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 75.458 sec
[junit] Running org.apache.hadoop.mapreduce.lib.input.TestFileInputFormat
[junit] 2010-10-27 05:59:54,310 WARN conf.Configuration
(Configuration.java:set(582)) - fs.default.name is deprecated. Instead, use
fs.defaultFS
[junit] 2010-10-27 05:59:54,509 WARN conf.Configuration
(Configuration.java:set(582)) - fs.default.name is deprecated. Instead, use
fs.defaultFS
[junit] defaultfs.getUri() = s3://abc:x...@hostname
[junit] original = file:/foo
[junit] results = [file:/foo]
[junit] original = file:/bar
[junit] results = [file:/bar]
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.967 sec
[junit] Running
org.apache.hadoop.mapreduce.lib.output.TestFileOutputCommitter
[junit] 2010-10-27 05:59:55,984 INFO output.FileOutputCommitter
(FileOutputCommitter.java:commitTask(173)) - Saved output of task
'attempt_200707121733_0001_m_000000_0' to
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/data/output>
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.524 sec
checkfailure:
[touch] Creating
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/testsfailed>
BUILD FAILED
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build.xml>:760:
The following error occurred while executing this line:
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build.xml>:723:
The following error occurred while executing this line:
<https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build.xml>:784:
Tests failed!
Total time: 20 minutes 59 seconds
[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
