hadoop-mapreduce-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Hudson Server <hud...@hudson.apache.org>
Subject Build failed in Hudson: Hadoop-Mapreduce-trunk-Commit #518
Date Mon, 25 Oct 2010 23:40:38 GMT
See <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/518/changes>

Changes:

[gkesavan] HADOOP-7007: Update the hudson-test-patch ant target. Contributed by Giridharan
Kesavan.

[gkesavan] HADOOP-7007: Update the hudson-test-patch ant target. Contributed by Giridharan
Kesavan.

------------------------------------------
[...truncated 33836 lines...]
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:04,868 INFO  jvm.JvmMetrics
(JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=SHUFFLE, sessionId=
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:04,871 WARN  conf.Configuration
(Configuration.java:handleDeprecation(313)) - user.name is deprecated. Instead, use mapreduce.job.user.name
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:04,899 INFO  util.ProcessTree
(ProcessTree.java:isSetsidSupported(65)) - setsid exited with exit code 0
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:04,914 INFO  mapred.Task
(Task.java:initialize(515)) -  Using ResourceCalculatorPlugin : org.apache.hadoop.mapreduce.util.LinuxResourceCalculatorPlugin@1cffeb4
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:04,989 INFO  reduce.MergeManager
(MergeManager.java:<init>(178)) - MergerManager: memoryLimit=141387360, maxSingleShuffleLimit=35346840,
mergeThreshold=93315664, ioSortFactor=10, memToMemMergeOutputsThreshold=10
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:04,994 INFO  reduce.EventFetcher
(EventFetcher.java:run(61)) - attempt_20101025233828373_0002_r_000000_0 Thread started: EventFetcher
for fetching Map Completion Events
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,007 INFO  reduce.EventFetcher
(EventFetcher.java:run(69)) - attempt_20101025233828373_0002_r_000000_0: Got 1 new map-outputs
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,007 INFO  reduce.ShuffleScheduler
(ShuffleScheduler.java:getHost(303)) - Assiging localhost:38186 with 1 to fetcher#4
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,008 INFO  reduce.ShuffleScheduler
(ShuffleScheduler.java:getMapsForHost(333)) - assigned 1 of 1 to localhost:38186 to fetcher#4
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,247 INFO  reduce.Fetcher
(Fetcher.java:copyFromHost(217)) - for url=38186/mapOutput?job=job_20101025233828373_0002&reduce=0&map=attempt_20101025233828373_0002_m_000000_0
sent hash and receievd reply
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,250 INFO  reduce.Fetcher
(Fetcher.java:copyMapOutput(314)) - fetcher#4 about to shuffle output of map attempt_20101025233828373_0002_m_000000_0
decomp: 107 len: 111 to MEMORY
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,252 INFO  reduce.Fetcher
(Fetcher.java:shuffleToMemory(479)) - Read 107 bytes from map-output for attempt_20101025233828373_0002_m_000000_0
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,253 INFO  reduce.MergeManager
(MergeManager.java:closeInMemoryFile(277)) - closeInMemoryFile -> map-output of size: 107,
inMemoryMapOutputs.size() -> 1
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,254 INFO  reduce.ShuffleScheduler
(ShuffleScheduler.java:freeHost(345)) - localhost:38186 freed by fetcher#4 in 246s
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,257 INFO  reduce.MergeManager
(MergeManager.java:finalMerge(629)) - finalMerge called with 1 in-memory map-outputs and 0
on-disk map-outputs
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,278 INFO  mapred.Merger
(Merger.java:merge(549)) - Merging 1 sorted segments
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,278 INFO  mapred.Merger
(Merger.java:merge(648)) - Down to the last merge-pass, with 1 segments left of total size:
103 bytes
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,288 INFO  reduce.MergeManager
(MergeManager.java:finalMerge(701)) - Merged 1 segments, 107 bytes to disk to satisfy reduce
memory limit
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,289 INFO  reduce.MergeManager
(MergeManager.java:finalMerge(727)) - Merging 1 files, 111 bytes from disk
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,290 INFO  reduce.MergeManager
(MergeManager.java:finalMerge(742)) - Merging 0 segments, 0 bytes from memory into reduce
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,290 INFO  mapred.Merger
(Merger.java:merge(549)) - Merging 1 sorted segments
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,293 INFO  mapred.Merger
(Merger.java:merge(648)) - Down to the last merge-pass, with 1 segments left of total size:
103 bytes
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,310 WARN  conf.Configuration
(Configuration.java:set(582)) - mapred.skip.on is deprecated. Instead, use mapreduce.job.skiprecords
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:05,324 INFO  mapred.Task
(Task.java:done(840)) - Task:attempt_20101025233828373_0002_r_000000_0 is done. And is in
the process of commiting
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:07,366 INFO  mapred.Task
(Task.java:commit(1001)) - Task attempt_20101025233828373_0002_r_000000_0 is allowed to commit
now
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:07,370 INFO  output.FileOutputCommitter
(FileOutputCommitter.java:commitTask(173)) - Saved output of task 'attempt_20101025233828373_0002_r_000000_0'
to <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/data/out>
    [junit] attempt_20101025233828373_0002_r_000000_0: 2010-10-25 23:39:07,405 INFO  mapred.Task
(Task.java:sendDone(960)) - Task 'attempt_20101025233828373_0002_r_000000_0' done.
    [junit] 2010-10-25 23:39:11,027 INFO  mapred.TaskTracker (TaskTracker.java:reportProgress(2656))
- attempt_20101025233828373_0002_m_000001_0 0.0% 
    [junit] 2010-10-25 23:39:11,108 INFO  mapred.TaskTracker (TaskTracker.java:reportProgress(2656))
- attempt_20101025233828373_0002_m_000001_0 0.0% cleanup > map
    [junit] 2010-10-25 23:39:11,109 INFO  mapred.TaskTracker (TaskTracker.java:reportDone(2737))
- Task attempt_20101025233828373_0002_m_000001_0 is done.
    [junit] 2010-10-25 23:39:11,109 INFO  mapred.TaskTracker (TaskTracker.java:reportDone(2738))
- reported output size for attempt_20101025233828373_0002_m_000001_0  was -1
    [junit] 2010-10-25 23:39:11,110 INFO  mapred.TaskTracker (TaskTracker.java:addFreeSlots(2223))
- addFreeSlot : current free slots : 2
    [junit] 2010-10-25 23:39:11,279 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-25 23:39:11,279 INFO  util.ProcessTree (ProcessTree.java:sendSignal(137))
- Sending signal to all members of process group -8014: SIGTERM. Exit code 1
    [junit] 2010-10-25 23:39:11,819 INFO  mapreduce.Job (Job.java:monitorAndPrintJob(1099))
-  map 100% reduce 100%
    [junit] 2010-10-25 23:39:12,591 INFO  mapred.JvmManager (JvmManager.java:runChild(472))
- JVM : jvm_20101025233828373_0002_r_1374968347 exited with exit code 0. Number of tasks it
ran: 1
    [junit] 2010-10-25 23:39:12,929 INFO  mapred.JobInProgress (JobInProgress.java:completedTask(2636))
- Task 'attempt_20101025233828373_0002_m_000001_0' has completed task_20101025233828373_0002_m_000001
successfully.
    [junit] 2010-10-25 23:39:12,931 INFO  mapred.JobInProgress (JobInProgress.java:jobComplete(2837))
- Job job_20101025233828373_0002 has completed successfully.
    [junit] 2010-10-25 23:39:12,932 INFO  mapred.JobInProgress$JobSummary (JobInProgress.java:logJobSummary(3611))
- jobId=job_20101025233828373_0002,submitTime=1288049936537,launchTime=1288049936814,firstMapTaskLaunchTime=1288049940888,firstReduceTaskLaunchTime=1288049943906,firstJobSetupTaskLaunchTime=1288049937879,firstJobCleanupTaskLaunchTime=1288049949922,finishTime=1288049952931,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-25 23:39:12,937 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_20101025233828373_0002_hudson>
to <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/history/done/job_20101025233828373_0002_hudson>
    [junit] 2010-10-25 23:39:12,938 INFO  mapred.JobTracker (JobTracker.java:removeTaskEntry(1863))
- Removing task 'attempt_20101025233828373_0002_m_000000_0'
    [junit] 2010-10-25 23:39:12,938 INFO  mapred.JobTracker (JobTracker.java:removeTaskEntry(1863))
- Removing task 'attempt_20101025233828373_0002_m_000001_0'
    [junit] 2010-10-25 23:39:12,939 INFO  mapred.JobTracker (JobTracker.java:removeTaskEntry(1863))
- Removing task 'attempt_20101025233828373_0002_m_000002_0'
    [junit] 2010-10-25 23:39:12,939 INFO  mapred.JobTracker (JobTracker.java:removeTaskEntry(1863))
- Removing task 'attempt_20101025233828373_0002_r_000000_0'
    [junit] 2010-10-25 23:39:12,940 INFO  mapred.TaskTracker (TaskTracker.java:purgeJob(1972))
- Received 'KillJobAction' for job: job_20101025233828373_0002
    [junit] 2010-10-25 23:39:12,941 INFO  mapred.IndexCache (IndexCache.java:removeMap(141))
- Map ID attempt_20101025233828373_0002_m_000001_0 not found in cache
    [junit] 2010-10-25 23:39:12,960 INFO  mapred.UserLogCleaner (UserLogCleaner.java:markJobLogsForDeletion(174))
- Adding job_20101025233828373_0002 for user-log deletion with retainTimeStamp:1288136352950
    [junit] 2010-10-25 23:39:12,997 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_20101025233828373_0002_conf.xml>
to <https://hudson.apache.org/hudson/job/Hadoop-Mapreduce-trunk-Commit/ws/trunk/build/test/logs/history/done/job_20101025233828373_0002_conf.xml>
    [junit] 2010-10-25 23:39:13,032 INFO  mapred.TaskTracker (TaskTracker.java:purgeJob(1972))
- Received 'KillJobAction' for job: job_20101025233828373_0002
    [junit] 2010-10-25 23:39:13,042 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(1979))
- Unknown job job_20101025233828373_0002 being deleted.
    [junit] 2010-10-25 23:39:13,055 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_20101025233828373_0002_conf.xml>
    [junit] 2010-10-25 23:39:13,826 INFO  mapreduce.Job (Job.java:printTaskEvents(1200)) -
Task Id : attempt_20101025233828373_0002_m_000001_0, Status : SUCCEEDED
    [junit] attempt_20101025233828373_0002_m_000001_0: 2010-10-25 23:39:10,919 INFO  jvm.JvmMetrics
(JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=MAP, sessionId=
    [junit] attempt_20101025233828373_0002_m_000001_0: 2010-10-25 23:39:10,922 WARN  conf.Configuration
(Configuration.java:handleDeprecation(313)) - user.name is deprecated. Instead, use mapreduce.job.user.name
    [junit] attempt_20101025233828373_0002_m_000001_0: 2010-10-25 23:39:10,952 INFO  util.ProcessTree
(ProcessTree.java:isSetsidSupported(65)) - setsid exited with exit code 0
    [junit] attempt_20101025233828373_0002_m_000001_0: 2010-10-25 23:39:10,965 INFO  mapred.Task
(Task.java:initialize(515)) -  Using ResourceCalculatorPlugin : org.apache.hadoop.mapreduce.util.LinuxResourceCalculatorPlugin@3cc262
    [junit] attempt_20101025233828373_0002_m_000001_0: 2010-10-25 23:39:11,027 INFO  mapred.Task
(Task.java:runJobCleanupTask(1049)) - Cleaning up job
    [junit] attempt_20101025233828373_0002_m_000001_0: 2010-10-25 23:39:11,028 INFO  mapred.Task
(Task.java:runJobCleanupTask(1061)) - Committing job
    [junit] attempt_20101025233828373_0002_m_000001_0: 2010-10-25 23:39:11,043 INFO  mapred.Task
(Task.java:done(840)) - Task:attempt_20101025233828373_0002_m_000001_0 is done. And is in
the process of commiting
    [junit] attempt_20101025233828373_0002_m_000001_0: 2010-10-25 23:39:11,111 INFO  mapred.Task
(Task.java:sendDone(960)) - Task 'attempt_20101025233828373_0002_m_000001_0' done.
    [junit] 2010-10-25 23:39:13,832 INFO  mapreduce.Job (Job.java:monitorAndPrintJob(1108))
- Job complete: job_20101025233828373_0002
    [junit] 2010-10-25 23:39:13,833 INFO  mapred.AuditLogger (AuditLogger.java:logSuccess(84))
- USER=hudson	IP=127.0.0.1	OPERATION=VIEW_JOB_COUNTERS	TARGET=job_20101025233828373_0002 in
queue default	RESULT=SUCCESS
    [junit] 2010-10-25 23:39:13,838 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=3637
    [junit] 		SLOTS_MILLIS_REDUCES=3491
    [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=1290
    [junit] 		Failed Shuffles=0
    [junit] 		GC time elapsed (ms)=17
    [junit] 		Map input records=4
    [junit] 		Map output bytes=112
    [junit] 		Map output records=13
    [junit] 		Merged Map outputs=1
    [junit] 		PHYSICAL_MEMORY_BYTES=101941248
    [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=740507648
    [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-25 23:39:13,844 INFO  util.AsyncDiskService (AsyncDiskService.java:shutdown(111))
- Shutting down all AsyncDiskService threads...
    [junit] 2010-10-25 23:39:13,845 INFO  util.AsyncDiskService (AsyncDiskService.java:awaitTermination(140))
- All AsyncDiskService threads are terminated.
    [junit] 2010-10-25 23:39:13,846 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:37272
    [junit] 2010-10-25 23:39:13,847 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-25 23:39:16,297 INFO  mapred.JvmManager (JvmManager.java:runChild(472))
- JVM : jvm_20101025233828373_0002_m_-123940147 exited with exit code 0. Number of tasks it
ran: 1
    [junit] 2010-10-25 23:39:16,297 INFO  ipc.Server (Server.java:stop(1601)) - Stopping server
on 37272
    [junit] 2010-10-25 23:39:16,298 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 1 on 37272: exiting
    [junit] 2010-10-25 23:39:16,298 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 2 on 37272: exiting
    [junit] 2010-10-25 23:39:16,298 INFO  ipc.Server (Server.java:run(675)) - Stopping IPC
Server Responder
    [junit] 2010-10-25 23:39:16,298 INFO  ipc.Server (Server.java:run(475)) - Stopping IPC
Server listener on 37272
    [junit] 2010-10-25 23:39:16,298 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 0 on 37272: exiting
    [junit] 2010-10-25 23:39:16,298 INFO  mapred.TaskTracker (TaskTracker.java:shutdown(1256))
- Shutting down StatusHttpServer
    [junit] 2010-10-25 23:39:16,298 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 3 on 37272: exiting
    [junit] 2010-10-25 23:40:16,405 ERROR mapred.TaskTracker (TaskTracker.java:offerService(1584))
- Caught exception: java.io.IOException: Call to localhost/127.0.0.1:46536 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-25 23:40:16,407 INFO  util.AsyncDiskService (AsyncDiskService.java:shutdown(111))
- Shutting down all AsyncDiskService threads...
    [junit] 2010-10-25 23:40:16,407 INFO  util.AsyncDiskService (AsyncDiskService.java:awaitTermination(140))
- All AsyncDiskService threads are terminated.
    [junit] 2010-10-25 23:40:16,409 INFO  util.AsyncDiskService (AsyncDiskService.java:shutdown(111))
- Shutting down all AsyncDiskService threads...
    [junit] 2010-10-25 23:40:16,414 INFO  util.AsyncDiskService (AsyncDiskService.java:awaitTermination(140))
- All AsyncDiskService threads are terminated.
    [junit] 2010-10-25 23:40:16,414 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:48910
    [junit] 2010-10-25 23:40:16,415 INFO  ipc.Server (Server.java:stop(1601)) - Stopping server
on 48910
    [junit] 2010-10-25 23:40:16,415 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 0 on 48910: exiting
    [junit] 2010-10-25 23:40:16,415 INFO  ipc.Server (Server.java:run(475)) - Stopping IPC
Server listener on 48910
    [junit] 2010-10-25 23:40:16,415 INFO  ipc.Server (Server.java:run(675)) - Stopping IPC
Server Responder
    [junit] 2010-10-25 23:40:16,415 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-25 23:40:16,415 INFO  mapred.TaskTracker (TaskTracker.java:shutdown(1256))
- Shutting down StatusHttpServer
    [junit] 2010-10-25 23:40:16,415 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 2 on 48910: exiting
    [junit] 2010-10-25 23:40:16,415 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 1 on 48910: exiting
    [junit] 2010-10-25 23:40:16,415 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 3 on 48910: exiting
    [junit] 2010-10-25 23:40:16,419 ERROR mapred.TaskTracker (TaskTracker.java:offerService(1584))
- Caught exception: java.io.IOException: Call to localhost/127.0.0.1:46536 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-25 23:40:16,420 INFO  util.AsyncDiskService (AsyncDiskService.java:shutdown(111))
- Shutting down all AsyncDiskService threads...
    [junit] 2010-10-25 23:40:16,420 INFO  util.AsyncDiskService (AsyncDiskService.java:awaitTermination(140))
- All AsyncDiskService threads are terminated.
    [junit] 2010-10-25 23:40:16,420 INFO  mapred.JobTracker (JobTracker.java:close(1765))
- Stopping infoServer
    [junit] 2010-10-25 23:40:16,433 INFO  mapred.JobTracker (JobTracker.java:close(1773))
- Stopping interTrackerServer
    [junit] 2010-10-25 23:40:16,433 INFO  ipc.Server (Server.java:stop(1601)) - Stopping server
on 46536
    [junit] 2010-10-25 23:40:16,433 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 1 on 46536: exiting
    [junit] 2010-10-25 23:40:16,433 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 0 on 46536: exiting
    [junit] 2010-10-25 23:40:16,434 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 4 on 46536: exiting
    [junit] 2010-10-25 23:40:16,434 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 2 on 46536: exiting
    [junit] 2010-10-25 23:40:16,434 INFO  mapred.JobTracker (JobTracker.java:offerService(1760))
- Stopped interTrackerServer
    [junit] 2010-10-25 23:40:16,434 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 3 on 46536: exiting
    [junit] 2010-10-25 23:40:16,434 INFO  ipc.Server (Server.java:run(675)) - Stopping IPC
Server Responder
    [junit] 2010-10-25 23:40:16,434 INFO  mapred.JobTracker (JobTracker.java:stopExpireTrackersThread(1812))
- Stopping expireTrackers
    [junit] 2010-10-25 23:40:16,434 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 7 on 46536: exiting
    [junit] 2010-10-25 23:40:16,435 INFO  mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:terminate(108))
- Stopping Job Init Manager thread
    [junit] 2010-10-25 23:40:16,434 INFO  ipc.Server (Server.java:run(475)) - Stopping IPC
Server listener on 46536
    [junit] 2010-10-25 23:40:16,435 INFO  mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:run(61))
- JobInitManagerThread interrupted.
    [junit] 2010-10-25 23:40:16,435 INFO  mapred.EagerTaskInitializationListener (EagerTaskInitializationListener.java:run(65))
- Shutting down thread pool
    [junit] 2010-10-25 23:40:16,436 INFO  mapred.JobTracker (JobTracker.java:close(1783))
- Stopping expireLaunchingTasks
    [junit] 2010-10-25 23:40:16,436 INFO  jobhistory.JobHistory (JobHistory.java:shutDown(195))
- Interrupting History Cleaner
    [junit] 2010-10-25 23:40:16,436 INFO  jobhistory.JobHistory (JobHistory.java:run(544))
- History Cleaner thread exiting
    [junit] 2010-10-25 23:40:16,437 INFO  mapred.JobTracker (JobTracker.java:close(1806))
- stopped all jobtracker services
    [junit] 2010-10-25 23:40:16,437 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 9 on 46536: exiting
    [junit] 2010-10-25 23:40:16,438 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 8 on 46536: exiting
    [junit] 2010-10-25 23:40:16,437 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 5 on 46536: exiting
    [junit] 2010-10-25 23:40:16,437 INFO  ipc.Server (Server.java:run(1444)) - IPC Server
handler 6 on 46536: exiting
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 108.21 sec
    [junit] Running org.apache.hadoop.mapreduce.lib.input.TestFileInputFormat
    [junit] 2010-10-25 23:40:17,505 WARN  conf.Configuration (Configuration.java:set(582))
- fs.default.name is deprecated. Instead, use fs.defaultFS
    [junit] 2010-10-25 23:40:17,706 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.96 sec
    [junit] Running org.apache.hadoop.mapreduce.lib.output.TestFileOutputCommitter
    [junit] 2010-10-25 23:40:19,146 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.494 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: 21 minutes 54 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


Mime
View raw message