See http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/286/changes
Changes: [acmurthy] HADOOP-2112. Adding back changes to build.xml lost while reverting HADOOP-1622 i.e. http://svn.apache.org/viewvc?view=rev&revision=588771. [acmurthy] Preparing to merge HADOOP-2105 into branch-0.15. [acmurthy] Preparing to merge HADOOP-2103 into branch-0.15. [acmurthy] Reverting revision 589543. [acmurthy] Preparing to merge HADOOP-2103 and HADOOP-2105 into branch-0.15. [acmurthy] HADOOP-2102. Fix the deprecated ToolBase to pass its Configuration object to the superceding ToolRunner to ensure it picks up the appropriate configuration resources. Contributed by Dennis Kubes and Enis Soztutar. ------------------------------------------ [...truncated 32693 lines...] [junit] task_200710291233_0004_r_000000_0: 2007-10-29 12:34:40,103 INFO pipes.PipesReducer (PipesReducer.java:startApplication(68)) - starting application [junit] task_200710291233_0004_r_000000_0: 2007-10-29 12:34:40,244 INFO pipes.PipesReducer (PipesReducer.java:close(102)) - waiting for finish [junit] task_200710291233_0004_r_000000_0: 2007-10-29 12:34:40,248 INFO pipes.PipesReducer (PipesReducer.java:close(104)) - got done [junit] task_200710291233_0004_r_000000_0: 2007-10-29 12:34:40,259 INFO mapred.TaskRunner (Task.java:done(382)) - Task 'task_200710291233_0004_r_000000_0' done. [junit] 2007-10-29 12:34:40,976 INFO mapred.TaskTracker (TaskTracker.java:reportProgress(1347)) - task_200710291233_0004_r_000001_0 0.73099416% reduce > reduce [junit] 2007-10-29 12:34:40,978 INFO mapred.TaskTracker (TaskTracker.java:reportDone(1403)) - Task task_200710291233_0004_r_000001_0 is done. [junit] 2007-10-29 12:34:41,067 INFO mapred.TaskRunner (Task.java:saveTaskOutput(434)) - Saved output of task 'task_200710291233_0004_r_000001_0' to http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/data/pipes/output [junit] 2007-10-29 12:34:41,067 INFO mapred.JobInProgress (JobInProgress.java:completedTask(788)) - Task 'task_200710291233_0004_r_000001_0' has completed tip_200710291233_0004_r_000001 successfully. [junit] 2007-10-29 12:34:41,071 INFO dfs.StateChange (FSNamesystem.java:deleteInternal(1326)) - BLOCK* NameSystem.delete: blk_2790121966479823702 is added to invalidSet of 127.0.0.1:50011 [junit] 2007-10-29 12:34:41,071 INFO dfs.StateChange (FSNamesystem.java:deleteInternal(1326)) - BLOCK* NameSystem.delete: blk_2790121966479823702 is added to invalidSet of 127.0.0.1:50010 [junit] 2007-10-29 12:34:41,071 INFO dfs.StateChange (FSNamesystem.java:deleteInternal(1326)) - BLOCK* NameSystem.delete: blk_4279965212565022876 is added to invalidSet of 127.0.0.1:50010 [junit] 2007-10-29 12:34:41,072 INFO dfs.StateChange (FSNamesystem.java:deleteInternal(1326)) - BLOCK* NameSystem.delete: blk_4279965212565022876 is added to invalidSet of 127.0.0.1:50011 [junit] 2007-10-29 12:34:41,074 WARN dfs.StateChange (FSDirectory.java:unprotectedDelete(400)) - DIR* FSDirectory.unprotectedDelete: failed to remove /user/hudson/build/test/mapred/system/job_200710291233_0004 because it does not exist [junit] 2007-10-29 12:34:41,075 INFO mapred.JobInProgress (JobInProgress.java:isJobComplete(881)) - Job job_200710291233_0004 has completed successfully. [junit] 2007-10-29 12:34:41,450 INFO mapred.JobClient (JobClient.java:runJob(772)) - map 100% reduce 100% [junit] 2007-10-29 12:34:41,452 INFO mapred.JobClient (JobClient.java:runJob(814)) - Task Id : task_200710291233_0004_r_000001_0, Status : SUCCEEDED [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,175 WARN conf.Configuration (Configuration.java:loadResource(842)) - http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/mapred/local/1_0/taskTracker/jobcache/job_200710291233_0004/task_200710291233_0004_r_000001_0/job.xml :a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,211 INFO jvm.JvmMetrics (JvmMetrics.java:init(56)) - Initializing JVM Metrics with processName=SHUFFLE, sessionId= [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,426 INFO fs.FileSystem (InMemoryFileSystem.java:initialize(74)) - Initialized InMemoryFileSystem: ramfs://mapoutput13480046 of size (in bytes): 78643200 [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,427 INFO mapred.ReduceTask (ReduceTask.java:<init>(831)) - task_200710291233_0004_r_000001_0 Created an InMemoryFileSystem, uri: ramfs://mapoutput13480046 [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,437 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(897)) - task_200710291233_0004_r_000001_0 Need 2 map output(s) [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,450 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(916)) - task_200710291233_0004_r_000001_0: Got 1 new map-outputs & 0 obsolete map-outputs from tasktracker and 0 map-outputs from previous failures [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,451 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(937)) - task_200710291233_0004_r_000001_0 Got 1 known map output location(s); scheduling... [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,451 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(977)) - task_200710291233_0004_r_000001_0 Scheduled 1 of 1 known outputs (0 slow hosts and 0 dup hosts) [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,451 INFO mapred.ReduceTask (ReduceTask.java:copyOutput(703)) - task_200710291233_0004_r_000001_0 Copying task_200710291233_0004_m_000000_0 output from lucene.zones.apache.org. [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,473 INFO mapred.ReduceTask (ReduceTask.java:copyOutput(751)) - task_200710291233_0004_r_000001_0 done copying task_200710291233_0004_m_000000_0 output from lucene.zones.apache.org. [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:34,477 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(897)) - task_200710291233_0004_r_000001_0 Need 1 map output(s) [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:35,441 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(916)) - task_200710291233_0004_r_000001_0: Got 0 new map-outputs & 0 obsolete map-outputs from tasktracker and 0 map-outputs from previous failures [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:35,442 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(937)) - task_200710291233_0004_r_000001_0 Got 0 known map output location(s); scheduling... [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:35,442 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(977)) - task_200710291233_0004_r_000001_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts) [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,449 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(897)) - task_200710291233_0004_r_000001_0 Need 1 map output(s) [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,452 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(916)) - task_200710291233_0004_r_000001_0: Got 1 new map-outputs & 0 obsolete map-outputs from tasktracker and 0 map-outputs from previous failures [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,453 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(937)) - task_200710291233_0004_r_000001_0 Got 1 known map output location(s); scheduling... [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,453 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(977)) - task_200710291233_0004_r_000001_0 Scheduled 1 of 1 known outputs (0 slow hosts and 0 dup hosts) [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,453 INFO mapred.ReduceTask (ReduceTask.java:copyOutput(703)) - task_200710291233_0004_r_000001_0 Copying task_200710291233_0004_m_000001_0 output from lucene.zones.apache.org. [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,462 INFO mapred.ReduceTask (ReduceTask.java:copyOutput(751)) - task_200710291233_0004_r_000001_0 done copying task_200710291233_0004_m_000001_0 output from lucene.zones.apache.org. [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,480 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(1121)) - task_200710291233_0004_r_000001_0 Copying of all map outputs complete. Initiating the last merge on the remaining files in ramfs://mapoutput13480046 [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,842 INFO mapred.ReduceTask (ReduceTask.java:fetchOutputs(1165)) - task_200710291233_0004_r_000001_0 Merge of the 2 files in InMemoryFileSystem complete. Local file is http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/mapred/local/1_0/task_200710291233_0004_r_000001_0/map_0.out [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,863 INFO pipes.PipesReducer (PipesReducer.java:startApplication(68)) - starting application [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,972 INFO pipes.PipesReducer (PipesReducer.java:close(102)) - waiting for finish [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,974 INFO pipes.PipesReducer (PipesReducer.java:close(104)) - got done [junit] task_200710291233_0004_r_000001_0: 2007-10-29 12:34:40,979 INFO mapred.TaskRunner (Task.java:done(382)) - Task 'task_200710291233_0004_r_000001_0' done. [junit] 2007-10-29 12:34:42,269 INFO dfs.StateChange (FSNamesystem.java:blocksToInvalidate(2789)) - BLOCK* NameSystem.blockToInvalidate: ask 127.0.0.1:50010 to delete blk_2790121966479823702 blk_4279965212565022876 [junit] 2007-10-29 12:34:42,270 INFO dfs.StateChange (FSNamesystem.java:blocksToInvalidate(2789)) - BLOCK* NameSystem.blockToInvalidate: ask 127.0.0.1:50011 to delete blk_2790121966479823702 blk_4279965212565022876 [junit] 2007-10-29 12:34:42,459 INFO mapred.JobClient (JobClient.java:runJob(833)) - Job complete: job_200710291233_0004 [junit] 2007-10-29 12:34:42,461 INFO mapred.JobClient (Counters.java:log(367)) - Counters: 6 [junit] 2007-10-29 12:34:42,461 INFO mapred.JobClient (Counters.java:log(371)) - Job Counters [junit] 2007-10-29 12:34:42,462 INFO mapred.JobClient (Counters.java:log(373)) - Launched map tasks=2 [junit] 2007-10-29 12:34:42,462 INFO mapred.JobClient (Counters.java:log(373)) - Launched reduce tasks=2 [junit] 2007-10-29 12:34:42,462 INFO mapred.JobClient (Counters.java:log(371)) - Map-Reduce Framework [junit] 2007-10-29 12:34:42,463 INFO mapred.JobClient (Counters.java:log(373)) - Map output records=13 [junit] 2007-10-29 12:34:42,463 INFO mapred.JobClient (Counters.java:log(373)) - Map output bytes=86 [junit] 2007-10-29 12:34:42,463 INFO mapred.JobClient (Counters.java:log(373)) - Reduce input groups=11 [junit] 2007-10-29 12:34:42,463 INFO mapred.JobClient (Counters.java:log(373)) - Reduce input records=13 [junit] 2007-10-29 12:34:42,464 INFO mapred.MiniMRCluster (MiniMRCluster.java:waitUntilIdle(206)) - Waiting for task tracker tracker_lucene.zones.apache.org:/127.0.0.1:57890 to be idle. [junit] 2007-10-29 12:34:42,668 INFO mapred.JobTracker (JobTracker.java:removeMarkedTasks(901)) - Removed completed task 'task_200710291233_0004_m_000000_0' from 'tracker_lucene.zones.apache.org:/127.0.0.1:57890' [junit] 2007-10-29 12:34:42,684 INFO mapred.JobTracker (JobTracker.java:removeMarkedTasks(901)) - Removed completed task 'task_200710291233_0004_r_000000_0' from 'tracker_lucene.zones.apache.org:/127.0.0.1:57890' [junit] 2007-10-29 12:34:42,685 INFO mapred.TaskTracker (TaskTracker.java:purgeJob(994)) - Received 'KillJobAction' for job: job_200710291233_0004 [junit] 2007-10-29 12:34:42,686 INFO mapred.TaskRunner (MapTaskRunner.java:close(41)) - task_200710291233_0004_m_000000_0 done; removing files. [junit] 2007-10-29 12:34:42,689 INFO mapred.TaskRunner (ReduceTaskRunner.java:close(45)) - task_200710291233_0004_r_000000_0 done; removing files. [junit] 2007-10-29 12:34:42,820 INFO dfs.DataNode (FSDataset.java:invalidate(709)) - Deleting block blk_2790121966479823702 file http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/data/dfs/data/data1/current/blk_2790121966479823702 [junit] 2007-10-29 12:34:42,821 INFO dfs.DataNode (FSDataset.java:invalidate(709)) - Deleting block blk_4279965212565022876 file http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/data/dfs/data/data2/current/blk_4279965212565022876 [junit] 2007-10-29 12:34:43,147 INFO dfs.DataNode (FSDataset.java:invalidate(709)) - Deleting block blk_2790121966479823702 file http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/data/dfs/data/data3/current/blk_2790121966479823702 [junit] 2007-10-29 12:34:43,148 INFO dfs.DataNode (FSDataset.java:invalidate(709)) - Deleting block blk_4279965212565022876 file http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/data/dfs/data/data4/current/blk_4279965212565022876 [junit] 2007-10-29 12:34:43,469 INFO mapred.MiniMRCluster (MiniMRCluster.java:waitUntilIdle(206)) - Waiting for task tracker tracker_lucene.zones.apache.org:/127.0.0.1:57892 to be idle. [junit] 2007-10-29 12:34:43,870 INFO mapred.JobTracker (JobTracker.java:removeMarkedTasks(901)) - Removed completed task 'task_200710291233_0004_m_000001_0' from 'tracker_lucene.zones.apache.org:/127.0.0.1:57892' [junit] 2007-10-29 12:34:43,870 INFO mapred.JobTracker (JobTracker.java:removeMarkedTasks(901)) - Removed completed task 'task_200710291233_0004_r_000001_0' from 'tracker_lucene.zones.apache.org:/127.0.0.1:57892' [junit] 2007-10-29 12:34:43,871 INFO mapred.TaskTracker (TaskTracker.java:purgeJob(994)) - Received 'KillJobAction' for job: job_200710291233_0004 [junit] 2007-10-29 12:34:43,871 INFO mapred.TaskRunner (ReduceTaskRunner.java:close(45)) - task_200710291233_0004_r_000001_0 done; removing files. [junit] 2007-10-29 12:34:43,873 INFO mapred.TaskRunner (MapTaskRunner.java:close(41)) - task_200710291233_0004_m_000001_0 done; removing files. [junit] 2007-10-29 12:34:44,500 INFO ipc.Server (Server.java:stop(677)) - Stopping server on 57890 [junit] 2007-10-29 12:34:44,501 INFO ipc.Server (Server.java:run(316)) - Stopping IPC Server listener on 57890 [junit] 2007-10-29 12:34:44,501 INFO mapred.TaskTracker (TaskTracker.java:shutdown(649)) - Shutting down StatusHttpServer [junit] 2007-10-29 12:34:44,501 INFO mapred.TaskTracker (TaskTracker.java:run(511)) - Shutting down: Map-events fetcher for all reduce tasks on tracker_lucene.zones.apache.org:/127.0.0.1:57890 [junit] 2007-10-29 12:34:44,502 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 1 on 57890: exiting [junit] 2007-10-29 12:34:44,503 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 0 on 57890: exiting [junit] 2007-10-29 12:34:44,503 INFO util.ThreadedServer (ThreadedServer.java:run(656)) - Stopping Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=50060] [junit] 2007-10-29 12:34:44,509 INFO http.SocketListener (SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:50060 [junit] 2007-10-29 12:34:44,510 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:44,656 INFO util.Container (Container.java:stop(156)) - Stopped WebApplicationContext[/,/] [junit] 2007-10-29 12:34:44,787 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/logs,/logs] [junit] 2007-10-29 12:34:44,932 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/static,/static] [junit] 2007-10-29 12:34:44,933 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:44,933 INFO mapred.TaskTracker (TaskTracker.java:offerService(829)) - Interrupted. Closing down. [junit] 2007-10-29 12:34:44,936 INFO ipc.Server (Server.java:stop(677)) - Stopping server on 57892 [junit] 2007-10-29 12:34:44,937 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 0 on 57892: exiting [junit] 2007-10-29 12:34:44,937 INFO mapred.TaskTracker (TaskTracker.java:run(511)) - Shutting down: Map-events fetcher for all reduce tasks on tracker_lucene.zones.apache.org:/127.0.0.1:57892 [junit] 2007-10-29 12:34:44,937 INFO mapred.TaskTracker (TaskTracker.java:shutdown(649)) - Shutting down StatusHttpServer [junit] 2007-10-29 12:34:44,937 INFO ipc.Server (Server.java:run(316)) - Stopping IPC Server listener on 57892 [junit] 2007-10-29 12:34:44,939 INFO http.SocketListener (SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:50061 [junit] 2007-10-29 12:34:44,937 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 1 on 57892: exiting [junit] 2007-10-29 12:34:44,940 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:45,054 INFO util.Container (Container.java:stop(156)) - Stopped WebApplicationContext[/,/] [junit] 2007-10-29 12:34:45,167 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/logs,/logs] [junit] 2007-10-29 12:34:45,280 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/static,/static] [junit] 2007-10-29 12:34:45,281 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:45,281 INFO mapred.TaskTracker (TaskTracker.java:offerService(829)) - Interrupted. Closing down. [junit] 2007-10-29 12:34:45,282 INFO mapred.JobTracker (JobTracker.java:close(739)) - Stopping infoServer [junit] 2007-10-29 12:34:45,284 INFO http.SocketListener (SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:57888 [junit] 2007-10-29 12:34:45,284 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:45,406 INFO util.Container (Container.java:stop(156)) - Stopped WebApplicationContext[/,/] [junit] 2007-10-29 12:34:45,517 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/logs,/logs] [junit] 2007-10-29 12:34:45,632 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/static,/static] [junit] 2007-10-29 12:34:45,633 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:45,633 INFO mapred.JobTracker (JobTracker.java:close(747)) - Stopping interTrackerServer [junit] 2007-10-29 12:34:45,633 INFO ipc.Server (Server.java:stop(677)) - Stopping server on 57887 [junit] 2007-10-29 12:34:45,634 INFO mapred.JobTracker (JobTracker.java:close(751)) - Stopping expireTrackers [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 9 on 57887: exiting [junit] 2007-10-29 12:34:45,634 INFO mapred.JobTracker (JobTracker.java:offerService(734)) - Stopped interTrackerServer [junit] 2007-10-29 12:34:45,635 ERROR mapred.JobTracker (JobTracker.java:run(308)) - Tracker Expiry Thread got exception: java.lang.InterruptedException: sleep interrupted [junit] at java.lang.Thread.sleep(Native Method) [junit] at org.apache.hadoop.mapred.JobTracker$ExpireTrackers.run(JobTracker.java:263) [junit] at java.lang.Thread.run(Thread.java:595) [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 7 on 57887: exiting [junit] 2007-10-29 12:34:45,635 INFO mapred.JobTracker (JobTracker.java:close(761)) - Stopping retirer [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 5 on 57887: exiting [junit] 2007-10-29 12:34:45,637 INFO mapred.JobTracker (JobTracker.java:close(770)) - Stopping initer [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 8 on 57887: exiting [junit] 2007-10-29 12:34:45,637 INFO mapred.JobTracker (JobTracker.java:close(779)) - Stopping expireLaunchingTasks [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 2 on 57887: exiting [junit] 2007-10-29 12:34:45,638 INFO mapred.JobTracker (JobTracker.java:close(789)) - Stopping TaskCommit thread [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 4 on 57887: exiting [junit] 2007-10-29 12:34:45,639 WARN mapred.JobTracker (JobTracker.java:run(2014)) - Task Commit Thread exiting, got interrupted: java.lang.InterruptedException [junit] at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:1815) [junit] at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1850) [junit] at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359) [junit] at org.apache.hadoop.mapred.JobTracker$TaskCommitQueue.run(JobTracker.java:1916) [junit] 2007-10-29 12:34:45,639 INFO mapred.JobTracker (JobTracker.java:close(797)) - stopped all jobtracker services [junit] Shutting down the Mini HDFS Cluster [junit] Shutting down DataNode 1 [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 1 on 57887: exiting [junit] 2007-10-29 12:34:45,640 INFO util.ThreadedServer (ThreadedServer.java:run(656)) - Stopping Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=57885] [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(316)) - Stopping IPC Server listener on 57887 [junit] 2007-10-29 12:34:45,641 INFO http.SocketListener (SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:57885 [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 6 on 57887: exiting [junit] 2007-10-29 12:34:45,642 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 0 on 57887: exiting [junit] 2007-10-29 12:34:45,759 INFO util.Container (Container.java:stop(156)) - Stopped WebApplicationContext[/,/] [junit] 2007-10-29 12:34:45,634 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 3 on 57887: exiting [junit] 2007-10-29 12:34:45,876 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/logs,/logs] [junit] 2007-10-29 12:34:45,994 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/static,/static] [junit] 2007-10-29 12:34:45,995 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:45,997 INFO dfs.DataNode (DataNode.java:run(1512)) - Finishing DataNode in: FSDataset{dirpath='http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/data/dfs/data/data3/current,/export/home/hudson/hudson/jobs/Hadoop-Nightly/workspace/trunk/build/test/data/dfs/data/data4/current'} [junit] Shutting down DataNode 0 [junit] 2007-10-29 12:34:45,998 INFO http.SocketListener (SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:57884 [junit] 2007-10-29 12:34:45,999 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:46,107 INFO util.Container (Container.java:stop(156)) - Stopped WebApplicationContext[/,/] [junit] 2007-10-29 12:34:46,213 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/logs,/logs] [junit] 2007-10-29 12:34:46,323 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/static,/static] [junit] 2007-10-29 12:34:46,324 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:46,325 INFO dfs.DataNode (DataNode.java:run(1512)) - Finishing DataNode in: FSDataset{dirpath='http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build/test/data/dfs/data/data1/current,/export/home/hudson/hudson/jobs/Hadoop-Nightly/workspace/trunk/build/test/data/dfs/data/data2/current'} [junit] 2007-10-29 12:34:46,326 WARN fs.FSNamesystem (PendingReplicationBlocks.java:run(186)) - PendingReplicationMonitor thread received exception. java.lang.InterruptedException: sleep interrupted [junit] 2007-10-29 12:34:46,326 INFO util.ThreadedServer (ThreadedServer.java:run(656)) - Stopping Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=57879] [junit] 2007-10-29 12:34:46,327 INFO http.SocketListener (SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:57879 [junit] 2007-10-29 12:34:46,328 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:46,439 INFO util.Container (Container.java:stop(156)) - Stopped WebApplicationContext[/,/] [junit] 2007-10-29 12:34:46,543 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/logs,/logs] [junit] 2007-10-29 12:34:46,648 INFO util.Container (Container.java:stop(156)) - Stopped HttpContext[/static,/static] [junit] 2007-10-29 12:34:46,648 INFO util.Container (Container.java:stop(156)) - Stopped [EMAIL PROTECTED] [junit] 2007-10-29 12:34:46,649 INFO fs.FSNamesystem (FSEditLog.java:printStatistics(741)) - Number of transactions: 117 Total time for transactions(ms): 1 Number of syncs: 76 SyncTimes(ms): 201 94 [junit] 2007-10-29 12:34:46,651 INFO ipc.Server (Server.java:stop(677)) - Stopping server on 57877 [junit] 2007-10-29 12:34:46,652 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 0 on 57877: exiting [junit] 2007-10-29 12:34:46,652 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 5 on 57877: exiting [junit] 2007-10-29 12:34:46,653 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 1 on 57877: exiting [junit] 2007-10-29 12:34:46,653 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 9 on 57877: exiting [junit] 2007-10-29 12:34:46,654 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 2 on 57877: exiting [junit] 2007-10-29 12:34:46,654 INFO ipc.Server (Server.java:run(316)) - Stopping IPC Server listener on 57877 [junit] 2007-10-29 12:34:46,654 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 7 on 57877: exiting [junit] 2007-10-29 12:34:46,654 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 6 on 57877: exiting [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 87.64 sec [junit] 2007-10-29 12:34:46,660 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 3 on 57877: exiting [junit] 2007-10-29 12:34:46,662 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 4 on 57877: exiting [junit] 2007-10-29 12:34:46,662 INFO ipc.Server (Server.java:run(633)) - IPC Server handler 8 on 57877: exiting [junit] Running org.apache.hadoop.net.TestNetworkTopology [junit] 2007-10-29 12:34:47,952 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r1/h1:5020 [junit] 2007-10-29 12:34:47,957 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r1/h2:5020 [junit] 2007-10-29 12:34:47,959 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r2/h3:5020 [junit] 2007-10-29 12:34:47,960 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r2/h4:5020 [junit] 2007-10-29 12:34:47,961 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r2/h5:5020 [junit] 2007-10-29 12:34:47,962 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d2/r3/h6:5020 [junit] 2007-10-29 12:34:47,962 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d2/r3/h7:5020 [junit] 2007-10-29 12:34:48,012 INFO net.NetworkTopology (NetworkTopology.java:remove(351)) - Removing a node: /d1/r1/h1:5020 [junit] 2007-10-29 12:34:48,014 INFO net.NetworkTopology (NetworkTopology.java:remove(351)) - Removing a node: /d1/r1/h2:5020 [junit] 2007-10-29 12:34:48,015 INFO net.NetworkTopology (NetworkTopology.java:remove(351)) - Removing a node: /d1/r2/h3:5020 [junit] 2007-10-29 12:34:48,016 INFO net.NetworkTopology (NetworkTopology.java:remove(351)) - Removing a node: /d1/r2/h4:5020 [junit] 2007-10-29 12:34:48,017 INFO net.NetworkTopology (NetworkTopology.java:remove(351)) - Removing a node: /d1/r2/h5:5020 [junit] 2007-10-29 12:34:48,019 INFO net.NetworkTopology (NetworkTopology.java:remove(351)) - Removing a node: /d2/r3/h6:5020 [junit] 2007-10-29 12:34:48,021 INFO net.NetworkTopology (NetworkTopology.java:remove(351)) - Removing a node: /d2/r3/h7:5020 [junit] 2007-10-29 12:34:48,022 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r1/h1:5020 [junit] 2007-10-29 12:34:48,024 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r1/h2:5020 [junit] 2007-10-29 12:34:48,026 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r2/h3:5020 [junit] 2007-10-29 12:34:48,027 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r2/h4:5020 [junit] 2007-10-29 12:34:48,029 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d1/r2/h5:5020 [junit] 2007-10-29 12:34:48,030 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d2/r3/h6:5020 [junit] 2007-10-29 12:34:48,032 INFO net.NetworkTopology (NetworkTopology.java:add(320)) - Adding a new node: /d2/r3/h7:5020 [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.067 sec [junit] Running org.apache.hadoop.record.TestBuffer [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.346 sec [junit] Running org.apache.hadoop.record.TestRecordIO [junit] Illustrating toString bugT,102,4567,99344109427290,3.1449999809265137,1.5234,'random text,#000102030405060708090a0b0c0d0e0f101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f303132333435363738393a3b3c3d3e3f404142434445464748494a4b4c4d4e4f505152535455565758595a5b5c5d5e5f606162636465666768696a6b6c6d6e6f707172737475767778797a7b7c7d7e7f808182838485868788898a8b8c8d8e8f909192939495969798999a9b9c9d9e9fa0a1a2a3a4a5a6a7a8a9aaabacadaeafb0b1b2b3b4b5b6b7b8b9babbbcbdbebfc0c1c2c3c4c5c6c7c8c9cacbcccdcecfd0d1d2d3d4d5d6d7d8d9dadbdcdddedfe0e1e2e3e4e5e6e7e8e9eaebecedeeeff0f1f2f3f4f5f6f7f8f9fafbfcfdfeff,v{},m{},s{'other random text} [junit] Illustrating toString bugT,102,4567,99344109427290,3.1449999809265137,1.5234,'random text,#000102030405060708090a0b0c0d0e0f101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f303132333435363738393a3b3c3d3e3f404142434445464748494a4b4c4d4e4f505152535455565758595a5b5c5d5e5f606162636465666768696a6b6c6d6e6f707172737475767778797a7b7c7d7e7f808182838485868788898a8b8c8d8e8f909192939495969798999a9b9c9d9e9fa0a1a2a3a4a5a6a7a8a9aaabacadaeafb0b1b2b3b4b5b6b7b8b9babbbcbdbebfc0c1c2c3c4c5c6c7c8c9cacbcccdcecfd0d1d2d3d4d5d6d7d8d9dadbdcdddedfe0e1e2e3e4e5e6e7e8e9eaebecedeeeff0f1f2f3f4f5f6f7f8f9fafbfcfdfeff,v{},m{},s{'other random text} [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 1.537 sec [junit] Running org.apache.hadoop.record.TestRecordMR [junit] 2007-10-29 12:34:53,295 INFO jvm.JvmMetrics (JvmMetrics.java:init(56)) - Initializing JVM Metrics with processName=JobTracker, sessionId= [junit] 2007-10-29 12:34:53,356 WARN mapred.JobClient (JobClient.java:submitJob(496)) - No job jar file set. User classes may not be found. See JobConf(Class) or JobConf#setJar(String). [junit] 2007-10-29 12:34:53,396 INFO mapred.FileInputFormat (FileInputFormat.java:validateInput(157)) - Total input paths to process : 1 [junit] 2007-10-29 12:34:53,807 WARN conf.Configuration (Configuration.java:loadResource(842)) - build/test/mapred/local/localRunner/job_local_1.xml:a attempt to override final parameter: hadoop.tmp.dir; Ignoring. [junit] 2007-10-29 12:34:53,966 INFO mapred.JobClient (JobClient.java:runJob(755)) - Running job: job_local_1 [junit] 2007-10-29 12:34:54,039 INFO mapred.MapTask (MapTask.java:run(127)) - numReduceTasks: 1 [junit] 2007-10-29 12:34:54,236 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(210)) - http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/mapred.loadtest/genins/answer.key :0+190 [junit] 2007-10-29 12:34:54,237 INFO mapred.TaskRunner (Task.java:done(382)) - Task 'map_0000' done. [junit] 2007-10-29 12:34:54,309 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(210)) - reduce > reduce [junit] 2007-10-29 12:34:54,309 INFO mapred.TaskRunner (Task.java:done(382)) - Task 'reduce_yk256x' done. [junit] 2007-10-29 12:34:54,315 INFO mapred.TaskRunner (Task.java:saveTaskOutput(434)) - Saved output of task 'reduce_yk256x' to http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/mapred.loadtest/genouts [junit] 2007-10-29 12:34:54,977 INFO mapred.JobClient (JobClient.java:runJob(833)) - Job complete: job_local_1 [junit] 2007-10-29 12:34:54,978 INFO mapred.JobClient (Counters.java:log(367)) - Counters: 7 [junit] 2007-10-29 12:34:54,982 INFO mapred.JobClient (Counters.java:log(371)) - Map-Reduce Framework [junit] 2007-10-29 12:34:54,983 INFO mapred.JobClient (Counters.java:log(373)) - Map input records=10 [junit] 2007-10-29 12:34:54,983 INFO mapred.JobClient (Counters.java:log(373)) - Map output records=100 [junit] 2007-10-29 12:34:54,984 INFO mapred.JobClient (Counters.java:log(373)) - Map input bytes=100 [junit] 2007-10-29 12:34:54,984 INFO mapred.JobClient (Counters.java:log(373)) - Map output bytes=700 [junit] 2007-10-29 12:34:54,985 INFO mapred.JobClient (Counters.java:log(373)) - Reduce input groups=100 [junit] 2007-10-29 12:34:54,985 INFO mapred.JobClient (Counters.java:log(373)) - Reduce input records=100 [junit] 2007-10-29 12:34:54,986 INFO mapred.JobClient (Counters.java:log(373)) - Reduce output records=100 [junit] 2007-10-29 12:34:55,000 INFO jvm.JvmMetrics (JvmMetrics.java:init(51)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized [junit] 2007-10-29 12:34:55,004 WARN mapred.JobClient (JobClient.java:submitJob(496)) - No job jar file set. User classes may not be found. See JobConf(Class) or JobConf#setJar(String). [junit] 2007-10-29 12:34:55,005 INFO mapred.FileInputFormat (FileInputFormat.java:validateInput(157)) - Total input paths to process : 1 [junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 2.96 sec [junit] Test org.apache.hadoop.record.TestRecordMR FAILED [junit] Running org.apache.hadoop.record.TestRecordWritable [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 4.554 sec [junit] Running org.apache.hadoop.util.TestReflectionUtils [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.891 sec BUILD FAILED http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/ws/trunk/build.xml :511: Tests failed! Total time: 43 minutes 0 seconds Recording fingerprints Publishing Javadoc Recording test results Updating HADOOP-2103 Updating HADOOP-2105 Updating HADOOP-2112 Updating HADOOP-2102 Updating HADOOP-1622
