See <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/511/changes>
Changes:
[schen] MAPREDUCE-2132. A command line option in RaidShell to fix blocks using raid
------------------------------------------
[...truncated 33913 lines...]
[junit] 2010-10-21 21:22:39,868 INFO mapred.TaskTracker (TaskTracker.java:reportProgress(2656))
- attempt_20101021212202824_0002_r_000000_0 0.0% 1 / 1 copied.
[junit] 2010-10-21 21:22:40,199 INFO mapreduce.Job (Job.java:monitorAndPrintJob(1099))
- map 100% reduce 0%
[junit] 2010-10-21 21:22:41,375 INFO mapred.TaskTracker (TaskTracker.java:offerService(1542))
- Received commit task action for attempt_20101021212202824_0002_r_000000_0
[junit] 2010-10-21 21:22:41,804 INFO mapred.JvmManager (JvmManager.java:runChild(472))
- JVM : jvm_20101021212202824_0002_m_1411948311 exited with exit code 0. Number of tasks it
ran: 1
[junit] 2010-10-21 21:22:41,911 INFO mapred.TaskTracker (TaskTracker.java:reportProgress(2656))
- attempt_20101021212202824_0002_r_000000_0 1.0% reduce > reduce
[junit] 2010-10-21 21:22:41,912 INFO mapred.TaskTracker (TaskTracker.java:reportDone(2737))
- Task attempt_20101021212202824_0002_r_000000_0 is done.
[junit] 2010-10-21 21:22:41,913 INFO mapred.TaskTracker (TaskTracker.java:reportDone(2738))
- reported output size for attempt_20101021212202824_0002_r_000000_0 was -1
[junit] 2010-10-21 21:22:41,914 INFO mapred.TaskTracker (TaskTracker.java:addFreeSlots(2223))
- addFreeSlot : current free slots : 2
[junit] 2010-10-21 21:22:42,085 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-21 21:22:42,086 INFO util.ProcessTree (ProcessTree.java:sendSignal(137))
- Sending signal to all members of process group -10873: SIGTERM. Exit code 1
[junit] 2010-10-21 21:22:44,380 INFO mapred.JobInProgress (JobInProgress.java:completedTask(2641))
- Task 'attempt_20101021212202824_0002_r_000000_0' has completed task_20101021212202824_0002_r_000000
successfully.
[junit] 2010-10-21 21:22:44,384 INFO mapred.JobTracker (JobTracker.java:createTaskEntry(1828))
- Adding task (JOB_CLEANUP) 'attempt_20101021212202824_0002_m_000001_0' to tip task_20101021212202824_0002_m_000001,
for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:56837'
[junit] 2010-10-21 21:22:44,385 INFO mapred.TaskTracker (TaskTracker.java:registerTask(2315))
- LaunchTaskAction (registerTask): attempt_20101021212202824_0002_m_000001_0 task's state:UNASSIGNED
[junit] 2010-10-21 21:22:44,386 INFO mapred.TaskTracker (TaskTracker.java:processKillTaskAction(426))
- Received KillTaskAction for task: attempt_20101021212202824_0002_r_000000_0
[junit] 2010-10-21 21:22:44,386 INFO mapred.TaskTracker (TaskTracker.java:run(2252))
- Trying to launch : attempt_20101021212202824_0002_m_000001_0 which needs 1 slots
[junit] 2010-10-21 21:22:44,386 INFO mapred.TaskTracker (TaskTracker.java:purgeTask(2041))
- About to purge task: attempt_20101021212202824_0002_r_000000_0
[junit] 2010-10-21 21:22:44,386 INFO mapred.TaskTracker (TaskTracker.java:run(2284))
- In TaskLauncher, current free slots : 2 and trying to launch attempt_20101021212202824_0002_m_000001_0
which needs 1 slots
[junit] 2010-10-21 21:22:44,387 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-21 21:22:44,440 INFO mapred.JvmManager (JvmManager.java:<init>(445))
- In JvmRunner constructed JVM ID: jvm_20101021212202824_0002_m_787331010
[junit] 2010-10-21 21:22:44,457 INFO mapred.JvmManager (JvmManager.java:spawnNewJvm(413))
- JVM Runner jvm_20101021212202824_0002_m_787331010 spawned.
[junit] 2010-10-21 21:22:45,210 INFO mapreduce.Job (Job.java:printTaskEvents(1200)) -
Task Id : attempt_20101021212202824_0002_r_000000_0, Status : SUCCEEDED
[junit] 2010-10-21 21:22:45,212 INFO mapred.TaskTracker (TaskTracker.java:getTask(3224))
- JVM with ID: jvm_20101021212202824_0002_m_787331010 given task: attempt_20101021212202824_0002_m_000001_0
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,332 INFO jvm.JvmMetrics
(JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=SHUFFLE, sessionId=
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,334 WARN conf.Configuration
(Configuration.java:handleDeprecation(313)) - user.name is deprecated. Instead, use mapreduce.job.user.name
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,363 INFO util.ProcessTree
(ProcessTree.java:isSetsidSupported(65)) - setsid exited with exit code 0
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,375 INFO mapred.Task
(Task.java:initialize(515)) - Using ResourceCalculatorPlugin : org.apache.hadoop.mapreduce.util.LinuxResourceCalculatorPlugin@14835fb
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,455 INFO reduce.MergeManager
(MergeManager.java:<init>(178)) - MergerManager: memoryLimit=141387360, maxSingleShuffleLimit=35346840,
mergeThreshold=93315664, ioSortFactor=10, memToMemMergeOutputsThreshold=10
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,461 INFO reduce.EventFetcher
(EventFetcher.java:run(61)) - attempt_20101021212202824_0002_r_000000_0 Thread started: EventFetcher
for fetching Map Completion Events
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,475 INFO reduce.ShuffleScheduler
(ShuffleScheduler.java:getHost(303)) - Assiging localhost:56977 with 1 to fetcher#5
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,475 INFO reduce.ShuffleScheduler
(ShuffleScheduler.java:getMapsForHost(333)) - assigned 1 of 1 to localhost:56977 to fetcher#5
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,475 INFO reduce.EventFetcher
(EventFetcher.java:run(69)) - attempt_20101021212202824_0002_r_000000_0: Got 1 new map-outputs
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,735 INFO reduce.Fetcher
(Fetcher.java:copyFromHost(217)) - for url=56977/mapOutput?job=job_20101021212202824_0002&reduce=0&map=attempt_20101021212202824_0002_m_000000_0
sent hash and receievd reply
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,738 INFO reduce.Fetcher
(Fetcher.java:copyMapOutput(314)) - fetcher#5 about to shuffle output of map attempt_20101021212202824_0002_m_000000_0
decomp: 107 len: 111 to MEMORY
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,740 INFO reduce.Fetcher
(Fetcher.java:shuffleToMemory(479)) - Read 107 bytes from map-output for attempt_20101021212202824_0002_m_000000_0
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,741 INFO reduce.MergeManager
(MergeManager.java:closeInMemoryFile(277)) - closeInMemoryFile -> map-output of size: 107,
inMemoryMapOutputs.size() -> 1
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,742 INFO reduce.ShuffleScheduler
(ShuffleScheduler.java:freeHost(345)) - localhost:56977 freed by fetcher#5 in 267s
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,745 INFO reduce.MergeManager
(MergeManager.java:finalMerge(629)) - finalMerge called with 1 in-memory map-outputs and 0
on-disk map-outputs
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,772 INFO mapred.Merger
(Merger.java:merge(549)) - Merging 1 sorted segments
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,773 INFO mapred.Merger
(Merger.java:merge(648)) - Down to the last merge-pass, with 1 segments left of total size:
103 bytes
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,785 INFO reduce.MergeManager
(MergeManager.java:finalMerge(701)) - Merged 1 segments, 107 bytes to disk to satisfy reduce
memory limit
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,786 INFO reduce.MergeManager
(MergeManager.java:finalMerge(727)) - Merging 1 files, 111 bytes from disk
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,787 INFO reduce.MergeManager
(MergeManager.java:finalMerge(742)) - Merging 0 segments, 0 bytes from memory into reduce
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,787 INFO mapred.Merger
(Merger.java:merge(549)) - Merging 1 sorted segments
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,790 INFO mapred.Merger
(Merger.java:merge(648)) - Down to the last merge-pass, with 1 segments left of total size:
103 bytes
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,808 WARN conf.Configuration
(Configuration.java:set(582)) - mapred.skip.on is deprecated. Instead, use mapreduce.job.skiprecords
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:39,825 INFO mapred.Task
(Task.java:done(840)) - Task:attempt_20101021212202824_0002_r_000000_0 is done. And is in
the process of commiting
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:41,875 INFO mapred.Task
(Task.java:commit(1001)) - Task attempt_20101021212202824_0002_r_000000_0 is allowed to commit
now
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:41,879 INFO output.FileOutputCommitter
(FileOutputCommitter.java:commitTask(173)) - Saved output of task 'attempt_20101021212202824_0002_r_000000_0'
to <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/data/out>
[junit] attempt_20101021212202824_0002_r_000000_0: 2010-10-21 21:22:41,913 INFO mapred.Task
(Task.java:sendDone(960)) - Task 'attempt_20101021212202824_0002_r_000000_0' done.
[junit] 2010-10-21 21:22:45,516 INFO mapred.TaskTracker (TaskTracker.java:reportProgress(2656))
- attempt_20101021212202824_0002_m_000001_0 0.0%
[junit] 2010-10-21 21:22:45,613 INFO mapred.TaskTracker (TaskTracker.java:reportProgress(2656))
- attempt_20101021212202824_0002_m_000001_0 0.0% cleanup > map
[junit] 2010-10-21 21:22:45,615 INFO mapred.TaskTracker (TaskTracker.java:reportDone(2737))
- Task attempt_20101021212202824_0002_m_000001_0 is done.
[junit] 2010-10-21 21:22:45,615 INFO mapred.TaskTracker (TaskTracker.java:reportDone(2738))
- reported output size for attempt_20101021212202824_0002_m_000001_0 was -1
[junit] 2010-10-21 21:22:45,616 INFO mapred.TaskTracker (TaskTracker.java:addFreeSlots(2223))
- addFreeSlot : current free slots : 2
[junit] 2010-10-21 21:22:45,796 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-21 21:22:45,797 INFO util.ProcessTree (ProcessTree.java:sendSignal(137))
- Sending signal to all members of process group -10949: SIGTERM. Exit code 1
[junit] 2010-10-21 21:22:46,219 INFO mapreduce.Job (Job.java:monitorAndPrintJob(1099))
- map 100% reduce 100%
[junit] 2010-10-21 21:22:47,104 INFO mapred.JvmManager (JvmManager.java:runChild(472))
- JVM : jvm_20101021212202824_0002_r_-151023137 exited with exit code 0. Number of tasks it
ran: 1
[junit] 2010-10-21 21:22:47,390 INFO mapred.JobInProgress (JobInProgress.java:completedTask(2641))
- Task 'attempt_20101021212202824_0002_m_000001_0' has completed task_20101021212202824_0002_m_000001
successfully.
[junit] 2010-10-21 21:22:47,392 INFO mapred.JobInProgress (JobInProgress.java:jobComplete(2842))
- Job job_20101021212202824_0002 has completed successfully.
[junit] 2010-10-21 21:22:47,392 INFO mapred.JobInProgress$JobSummary (JobInProgress.java:logJobSummary(3616))
- jobId=job_20101021212202824_0002,submitTime=1287696151070,launchTime=1287696151238,firstMapTaskLaunchTime=1287696155350,firstReduceTaskLaunchTime=1287696158367,firstJobSetupTaskLaunchTime=1287696152340,firstJobCleanupTaskLaunchTime=1287696164384,finishTime=1287696167392,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-21 21:22:47,397 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_20101021212202824_0002_hudson>
to <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/history/done/job_20101021212202824_0002_hudson>
[junit] 2010-10-21 21:22:47,398 INFO mapred.JobTracker (JobTracker.java:removeTaskEntry(1863))
- Removing task 'attempt_20101021212202824_0002_m_000000_0'
[junit] 2010-10-21 21:22:47,399 INFO mapred.JobTracker (JobTracker.java:removeTaskEntry(1863))
- Removing task 'attempt_20101021212202824_0002_m_000001_0'
[junit] 2010-10-21 21:22:47,400 INFO mapred.JobTracker (JobTracker.java:removeTaskEntry(1863))
- Removing task 'attempt_20101021212202824_0002_m_000002_0'
[junit] 2010-10-21 21:22:47,400 INFO mapred.JobTracker (JobTracker.java:removeTaskEntry(1863))
- Removing task 'attempt_20101021212202824_0002_r_000000_0'
[junit] 2010-10-21 21:22:47,401 INFO mapred.TaskTracker (TaskTracker.java:purgeJob(1972))
- Received 'KillJobAction' for job: job_20101021212202824_0002
[junit] 2010-10-21 21:22:47,402 INFO mapred.IndexCache (IndexCache.java:removeMap(141))
- Map ID attempt_20101021212202824_0002_m_000001_0 not found in cache
[junit] 2010-10-21 21:22:47,415 INFO mapred.UserLogCleaner (UserLogCleaner.java:markJobLogsForDeletion(174))
- Adding job_20101021212202824_0002 for user-log deletion with retainTimeStamp:1287782567415
[junit] 2010-10-21 21:22:47,443 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_20101021212202824_0002_conf.xml>
to <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/history/done/job_20101021212202824_0002_conf.xml>
[junit] 2010-10-21 21:22:47,472 INFO mapred.TaskTracker (TaskTracker.java:purgeJob(1972))
- Received 'KillJobAction' for job: job_20101021212202824_0002
[junit] 2010-10-21 21:22:47,472 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(1979))
- Unknown job job_20101021212202824_0002 being deleted.
[junit] 2010-10-21 21:22:47,495 INFO mapred.JobInProgress (JobInProgress.java:cleanupLocalizedJobConf(3657))
- Deleting localized job conf at <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/job_20101021212202824_0002_conf.xml>
[junit] 2010-10-21 21:22:48,227 INFO mapreduce.Job (Job.java:printTaskEvents(1200)) -
Task Id : attempt_20101021212202824_0002_m_000001_0, Status : SUCCEEDED
[junit] attempt_20101021212202824_0002_m_000001_0: 2010-10-21 21:22:45,409 INFO jvm.JvmMetrics
(JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=MAP, sessionId=
[junit] attempt_20101021212202824_0002_m_000001_0: 2010-10-21 21:22:45,411 WARN conf.Configuration
(Configuration.java:handleDeprecation(313)) - user.name is deprecated. Instead, use mapreduce.job.user.name
[junit] attempt_20101021212202824_0002_m_000001_0: 2010-10-21 21:22:45,442 INFO util.ProcessTree
(ProcessTree.java:isSetsidSupported(65)) - setsid exited with exit code 0
[junit] attempt_20101021212202824_0002_m_000001_0: 2010-10-21 21:22:45,455 INFO mapred.Task
(Task.java:initialize(515)) - Using ResourceCalculatorPlugin : org.apache.hadoop.mapreduce.util.LinuxResourceCalculatorPlugin@701a27
[junit] attempt_20101021212202824_0002_m_000001_0: 2010-10-21 21:22:45,517 INFO mapred.Task
(Task.java:runJobCleanupTask(1049)) - Cleaning up job
[junit] attempt_20101021212202824_0002_m_000001_0: 2010-10-21 21:22:45,517 INFO mapred.Task
(Task.java:runJobCleanupTask(1061)) - Committing job
[junit] attempt_20101021212202824_0002_m_000001_0: 2010-10-21 21:22:45,534 INFO mapred.Task
(Task.java:done(840)) - Task:attempt_20101021212202824_0002_m_000001_0 is done. And is in
the process of commiting
[junit] attempt_20101021212202824_0002_m_000001_0: 2010-10-21 21:22:45,616 INFO mapred.Task
(Task.java:sendDone(960)) - Task 'attempt_20101021212202824_0002_m_000001_0' done.
[junit] 2010-10-21 21:22:48,232 INFO mapreduce.Job (Job.java:monitorAndPrintJob(1108))
- Job complete: job_20101021212202824_0002
[junit] 2010-10-21 21:22:48,233 INFO mapred.AuditLogger (AuditLogger.java:logSuccess(84))
- USER=hudson IP=127.0.0.1 OPERATION=VIEW_JOB_COUNTERS TARGET=job_20101021212202824_0002 in
queue default RESULT=SUCCESS
[junit] 2010-10-21 21:22:48,237 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=3625
[junit] SLOTS_MILLIS_REDUCES=3538
[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=1310
[junit] Failed Shuffles=0
[junit] GC time elapsed (ms)=16
[junit] Map input records=4
[junit] Map output bytes=112
[junit] Map output records=13
[junit] Merged Map outputs=1
[junit] PHYSICAL_MEMORY_BYTES=101871616
[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=741711872
[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-21 21:22:48,243 INFO util.AsyncDiskService (AsyncDiskService.java:shutdown(111))
- Shutting down all AsyncDiskService threads...
[junit] 2010-10-21 21:22:48,244 INFO util.AsyncDiskService (AsyncDiskService.java:awaitTermination(140))
- All AsyncDiskService threads are terminated.
[junit] 2010-10-21 21:22:48,245 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:56837
[junit] 2010-10-21 21:22:48,246 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-21 21:22:50,814 INFO mapred.JvmManager (JvmManager.java:runChild(472))
- JVM : jvm_20101021212202824_0002_m_787331010 exited with exit code 0. Number of tasks it
ran: 1
[junit] 2010-10-21 21:22:50,814 INFO ipc.Server (Server.java:stop(1601)) - Stopping server
on 56837
[junit] 2010-10-21 21:22:50,815 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 0 on 56837: exiting
[junit] 2010-10-21 21:22:50,815 INFO ipc.Server (Server.java:run(475)) - Stopping IPC
Server listener on 56837
[junit] 2010-10-21 21:22:50,815 INFO ipc.Server (Server.java:run(675)) - Stopping IPC
Server Responder
[junit] 2010-10-21 21:22:50,815 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 1 on 56837: exiting
[junit] 2010-10-21 21:22:50,815 INFO mapred.TaskTracker (TaskTracker.java:shutdown(1256))
- Shutting down StatusHttpServer
[junit] 2010-10-21 21:22:50,815 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 2 on 56837: exiting
[junit] 2010-10-21 21:22:50,815 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 3 on 56837: exiting
[junit] 2010-10-21 21:22:50,823 ERROR mapred.TaskTracker (TaskTracker.java:offerService(1584))
- Caught exception: java.io.IOException: Call to localhost/127.0.0.1:45391 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-21 21:22:50,824 INFO util.AsyncDiskService (AsyncDiskService.java:shutdown(111))
- Shutting down all AsyncDiskService threads...
[junit] 2010-10-21 21:22:50,825 INFO util.AsyncDiskService (AsyncDiskService.java:awaitTermination(140))
- All AsyncDiskService threads are terminated.
[junit] 2010-10-21 21:22:50,828 INFO util.AsyncDiskService (AsyncDiskService.java:shutdown(111))
- Shutting down all AsyncDiskService threads...
[junit] 2010-10-21 21:22:50,829 INFO util.AsyncDiskService (AsyncDiskService.java:awaitTermination(140))
- All AsyncDiskService threads are terminated.
[junit] 2010-10-21 21:22:50,829 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:38224
[junit] 2010-10-21 21:22:50,829 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-21 21:22:50,829 INFO ipc.Server (Server.java:stop(1601)) - Stopping server
on 38224
[junit] 2010-10-21 21:22:50,830 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 0 on 38224: exiting
[junit] 2010-10-21 21:22:50,830 INFO ipc.Server (Server.java:run(475)) - Stopping IPC
Server listener on 38224
[junit] 2010-10-21 21:22:50,830 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 3 on 38224: exiting
[junit] 2010-10-21 21:22:50,830 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 2 on 38224: exiting
[junit] 2010-10-21 21:22:50,830 INFO ipc.Server (Server.java:run(675)) - Stopping IPC
Server Responder
[junit] 2010-10-21 21:22:50,830 INFO mapred.TaskTracker (TaskTracker.java:shutdown(1256))
- Shutting down StatusHttpServer
[junit] 2010-10-21 21:22:50,830 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 1 on 38224: exiting
[junit] 2010-10-21 21:22:50,832 INFO mapred.TaskTracker (TaskTracker.java:offerService(1564))
- Interrupted. Closing down.
[junit] 2010-10-21 21:22:50,833 INFO util.AsyncDiskService (AsyncDiskService.java:shutdown(111))
- Shutting down all AsyncDiskService threads...
[junit] 2010-10-21 21:22:50,833 INFO util.AsyncDiskService (AsyncDiskService.java:awaitTermination(140))
- All AsyncDiskService threads are terminated.
[junit] 2010-10-21 21:22:50,833 INFO mapred.JobTracker (JobTracker.java:close(1765))
- Stopping infoServer
[junit] 2010-10-21 21:22:50,935 INFO mapred.JobTracker (JobTracker.java:close(1773))
- Stopping interTrackerServer
[junit] 2010-10-21 21:22:50,935 INFO ipc.Server (Server.java:stop(1601)) - Stopping server
on 45391
[junit] 2010-10-21 21:22:50,935 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 0 on 45391: exiting
[junit] 2010-10-21 21:22:50,936 INFO ipc.Server (Server.java:run(475)) - Stopping IPC
Server listener on 45391
[junit] 2010-10-21 21:22:50,936 INFO ipc.Server (Server.java:run(675)) - Stopping IPC
Server Responder
[junit] 2010-10-21 21:22:50,936 INFO mapred.JobTracker (JobTracker.java:stopExpireTrackersThread(1812))
- Stopping expireTrackers
[junit] 2010-10-21 21:22:50,936 INFO mapred.JobTracker (JobTracker.java:offerService(1760))
- Stopped interTrackerServer
[junit] 2010-10-21 21:22:50,936 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 1 on 45391: exiting
[junit] 2010-10-21 21:22:50,937 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 5 on 45391: exiting
[junit] 2010-10-21 21:22:50,936 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 2 on 45391: exiting
[junit] 2010-10-21 21:22:50,937 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 8 on 45391: exiting
[junit] 2010-10-21 21:22:50,937 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 4 on 45391: exiting
[junit] 2010-10-21 21:22:50,937 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 3 on 45391: exiting
[junit] 2010-10-21 21:22:50,937 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 6 on 45391: exiting
[junit] 2010-10-21 21:22:50,937 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 9 on 45391: exiting
[junit] 2010-10-21 21:22:50,937 INFO mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:terminate(108))
- Stopping Job Init Manager thread
[junit] 2010-10-21 21:22:50,937 INFO ipc.Server (Server.java:run(1444)) - IPC Server
handler 7 on 45391: exiting
[junit] 2010-10-21 21:22:50,938 INFO mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:run(61))
- JobInitManagerThread interrupted.
[junit] 2010-10-21 21:22:50,938 INFO mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:run(65))
- Shutting down thread pool
[junit] 2010-10-21 21:22:50,939 INFO mapred.JobTracker (JobTracker.java:close(1783))
- Stopping expireLaunchingTasks
[junit] 2010-10-21 21:22:50,939 INFO jobhistory.JobHistory (JobHistory.java:shutDown(195))
- Interrupting History Cleaner
[junit] 2010-10-21 21:22:50,939 INFO jobhistory.JobHistory (JobHistory.java:run(544))
- History Cleaner thread exiting
[junit] 2010-10-21 21:22:50,939 INFO mapred.JobTracker (JobTracker.java:close(1806))
- stopped all jobtracker services
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 48.278 sec
[junit] Running org.apache.hadoop.mapreduce.lib.input.TestFileInputFormat
[junit] 2010-10-21 21:22:51,978 WARN conf.Configuration (Configuration.java:set(582))
- fs.default.name is deprecated. Instead, use fs.defaultFS
[junit] 2010-10-21 21:22:52,177 WARN conf.Configuration (Configuration.java:set(582))
- fs.default.name is deprecated. Instead, use fs.defaultFS
[junit] defaultfs.getUri() = s3://abc:xyz@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.977 sec
[junit] Running org.apache.hadoop.mapreduce.lib.output.TestFileOutputCommitter
[junit] 2010-10-21 21:22:53,632 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.51 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: 23 minutes 51 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
|