From mapreduce-dev-return-2548-apmail-hadoop-mapreduce-dev-archive=hadoop.apache.org@hadoop.apache.org Wed Oct 27 06:00:45 2010 Return-Path: Delivered-To: apmail-hadoop-mapreduce-dev-archive@minotaur.apache.org Received: (qmail 79790 invoked from network); 27 Oct 2010 06:00:45 -0000 Received: from unknown (HELO mail.apache.org) (140.211.11.3) by 140.211.11.9 with SMTP; 27 Oct 2010 06:00:45 -0000 Received: (qmail 50354 invoked by uid 500); 27 Oct 2010 06:00:44 -0000 Delivered-To: apmail-hadoop-mapreduce-dev-archive@hadoop.apache.org Received: (qmail 50017 invoked by uid 500); 27 Oct 2010 06:00:43 -0000 Mailing-List: contact mapreduce-dev-help@hadoop.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: mapreduce-dev@hadoop.apache.org Delivered-To: mailing list mapreduce-dev@hadoop.apache.org Received: (qmail 50008 invoked by uid 99); 27 Oct 2010 06:00:42 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 27 Oct 2010 06:00:42 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=10.0 tests=ALL_TRUSTED X-Spam-Check-By: apache.org Received: from [140.211.11.8] (HELO aegis.apache.org) (140.211.11.8) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 27 Oct 2010 06:00:36 +0000 Received: from aegis (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id 91001C0174 for ; Wed, 27 Oct 2010 06:00:14 +0000 (UTC) Date: Wed, 27 Oct 2010 06:00:14 +0000 (UTC) From: Apache Hudson Server To: mapreduce-dev@hadoop.apache.org Message-ID: <1856832223.13901288159214592.JavaMail.hudson@aegis> In-Reply-To: <816755193.13561288122077821.JavaMail.hudson@aegis> References: <816755193.13561288122077821.JavaMail.hudson@aegis> Subject: Build failed in Hudson: Hadoop-Mapreduce-trunk-Commit #520 MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit X-Virus-Checked: Checked by ClamAV on apache.org See 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:(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.LinuxResourceCalculatorPlugin@1687e7c [junit] attempt_20101027055837979_0002_r_000000_0: 2010-10-27 05:59:41,689 INFO reduce.MergeManager (MergeManager.java:(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 [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 to [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 to [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 [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.LinuxResourceCalculatorPlugin@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: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.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 [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.524 sec checkfailure: [touch] Creating BUILD FAILED :760: The following error occurred while executing this line: :723: The following error occurred while executing this line: :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