You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-dev@hadoop.apache.org by Apache Hudson Server <hu...@hudson.zones.apache.org> on 2009/05/14 20:02:53 UTC
Build failed in Hudson: Hadoop-trunk #836
See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/836/changes
Changes:
[rangadi] Remove a file that was mistakenly added earlier.
[rangadi] HADOOP-5823. Added a new class DeprecatedUTF8 to help with removing
UTF8 related javac warnings. These warnings are removed in
FSEditLog.java as a use case. (Raghu Angadi)
[rangadi] HADOOP-4359. Support for data access authorization checking on Datanodes.
(Kan Zhang via rangadi)
------------------------------------------
[...truncated 564571 lines...]
[junit] 09/05/14 18:18:05 INFO mapred.TaskTracker: About to purge task: attempt_200905141817_0001_m_000002_0
[junit] 09/05/14 18:18:05 INFO mapred.TaskRunner: attempt_200905141817_0001_m_000002_0 done; removing files.
[junit] 09/05/14 18:18:05 INFO mapred.IndexCache: Map ID attempt_200905141817_0001_m_000002_0 not found in cache
[junit] 09/05/14 18:18:05 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_200905141817_0001_m_-118297668
[junit] 09/05/14 18:18:05 INFO mapred.JvmManager: JVM Runner jvm_200905141817_0001_m_-118297668 spawned.
[junit] 09/05/14 18:18:05 INFO mapred.TaskTracker: JVM with ID: jvm_200905141817_0001_m_-118297668 given task: attempt_200905141817_0001_m_000000_0
[junit] 09/05/14 18:18:06 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/testing/in/part0 dst=null perm=null
[junit] 09/05/14 18:18:06 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:06 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:06 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/testing/out/_temporary/_attempt_200905141817_0001_m_000000_0 dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/05/14 18:18:06 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:06 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:06 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:06 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/testing/out/_temporary/_attempt_200905141817_0001_m_000000_0/part-00000 dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/05/14 18:18:06 INFO DataNode.clienttrace: src: /127.0.0.1:32850, dest: /127.0.0.1:54048, bytes: 19, op: HDFS_READ, cliID: DFSClient_attempt_200905141817_0001_m_000000_0, offset: 0, srvID: DS-161937833-67.195.138.9-32850-1242325070006, blockid: blk_1500170271161779435_1002, duration: 257830
[junit] 09/05/14 18:18:06 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /testing/out/_temporary/_attempt_200905141817_0001_m_000000_0/part-00000. blk_7209758248774497331_1008
[junit] 09/05/14 18:18:06 INFO datanode.DataNode: Receiving block blk_7209758248774497331_1008 src: /127.0.0.1:48338 dest: /127.0.0.1:60835
[junit] 09/05/14 18:18:06 INFO datanode.DataNode: Receiving block blk_7209758248774497331_1008 src: /127.0.0.1:54050 dest: /127.0.0.1:32850
[junit] 09/05/14 18:18:06 INFO DataNode.clienttrace: src: /127.0.0.1:54050, dest: /127.0.0.1:32850, bytes: 8, op: HDFS_WRITE, cliID: DFSClient_attempt_200905141817_0001_m_000000_0, offset: 0, srvID: DS-161937833-67.195.138.9-32850-1242325070006, blockid: blk_7209758248774497331_1008, duration: 1956999
[junit] 09/05/14 18:18:06 INFO datanode.DataNode: PacketResponder 0 for block blk_7209758248774497331_1008 terminating
[junit] 09/05/14 18:18:06 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:32850 is added to blk_7209758248774497331_1008 size 8
[junit] 09/05/14 18:18:06 INFO DataNode.clienttrace: src: /127.0.0.1:48338, dest: /127.0.0.1:60835, bytes: 8, op: HDFS_WRITE, cliID: DFSClient_attempt_200905141817_0001_m_000000_0, offset: 0, srvID: DS-720742920-67.195.138.9-60835-1242325069825, blockid: blk_7209758248774497331_1008, duration: 41678008
[junit] 09/05/14 18:18:06 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60835 is added to blk_7209758248774497331_1008 size 8
[junit] 09/05/14 18:18:06 INFO datanode.DataNode: PacketResponder 1 for block blk_7209758248774497331_1008 terminating
[junit] 09/05/14 18:18:06 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:06 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /testing/out/_temporary/_attempt_200905141817_0001_m_000000_0/part-00000 is closed by DFSClient_attempt_200905141817_0001_m_000000_0
[junit] 09/05/14 18:18:06 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:06 INFO mapred.TaskTracker: Task attempt_200905141817_0001_m_000000_0 is in commit-pending, task state:COMMIT_PENDING
[junit] 09/05/14 18:18:06 INFO mapred.TaskTracker: attempt_200905141817_0001_m_000000_0 0.0%
[junit] 09/05/14 18:18:08 INFO mapred.TaskTracker: Received commit task action for attempt_200905141817_0001_m_000000_0
[junit] 09/05/14 18:18:08 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/testing/out/_temporary/_attempt_200905141817_0001_m_000000_0 dst=null perm=null
[junit] 09/05/14 18:18:08 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/testing/out dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/05/14 18:18:08 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:08 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:08 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=rename src=/testing/out/_temporary/_attempt_200905141817_0001_m_000000_0/part-00000 dst=/testing/out/part-00000 perm=hudson:supergroup:rw-r--r--
[junit] 09/05/14 18:18:08 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:08 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:08 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/testing/out/_temporary/_attempt_200905141817_0001_m_000000_0 dst=null perm=null
[junit] 09/05/14 18:18:08 INFO mapred.TaskTracker: attempt_200905141817_0001_m_000000_0 1.0% Records R/W=1/1
[junit] 09/05/14 18:18:08 INFO mapred.TaskTracker: Task attempt_200905141817_0001_m_000000_0 is done.
[junit] 09/05/14 18:18:08 INFO mapred.TaskTracker: reported output size for attempt_200905141817_0001_m_000000_0 was 0
[junit] 09/05/14 18:18:08 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/05/14 18:18:08 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/14 18:18:08 INFO util.ProcessTree: Killing process group11092 with SIGKILL. Exit code 1
[junit] 09/05/14 18:18:08 INFO mapred.DefaultTaskController: Process exited with exit code:0
[junit] 09/05/14 18:18:08 INFO mapred.JvmManager: JVM : jvm_200905141817_0001_m_-892032358 exited. Number of tasks it ran: 1
[junit] 09/05/14 18:18:08 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/14 18:18:08 INFO util.ProcessTree: Killing all processes in the process group 11147 with SIGTERM. Exit code 1
[junit] 09/05/14 18:18:11 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_200905141817_0001/attempt_200905141817_0001_m_000000_0/output/file.out in any of the configured local directories
[junit] 09/05/14 18:18:11 INFO mapred.JobInProgress: Task 'attempt_200905141817_0001_m_000000_0' has completed task_200905141817_0001_m_000000 successfully.
[junit] 09/05/14 18:18:11 INFO mapred.JobTracker: Adding task 'attempt_200905141817_0001_m_000001_0' to tip task_200905141817_0001_m_000001, for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:33710'
[junit] 09/05/14 18:18:11 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_200905141817_0001_m_000001_0 task's state:UNASSIGNED
[junit] 09/05/14 18:18:11 INFO mapred.TaskTracker: Trying to launch : attempt_200905141817_0001_m_000001_0
[junit] 09/05/14 18:18:11 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_200905141817_0001_m_000001_0
[junit] 09/05/14 18:18:11 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_200905141817_0001_m_-1010643465
[junit] 09/05/14 18:18:11 INFO mapred.JvmManager: JVM Runner jvm_200905141817_0001_m_-1010643465 spawned.
[junit] 09/05/14 18:18:11 INFO mapred.TaskTracker: JVM with ID: jvm_200905141817_0001_m_-1010643465 given task: attempt_200905141817_0001_m_000001_0
[junit] 09/05/14 18:18:12 INFO streaming.StreamJob: map 100% reduce 0%
[junit] 09/05/14 18:18:12 INFO mapred.TaskTracker: attempt_200905141817_0001_m_000001_0 0.0%
[junit] 09/05/14 18:18:12 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:12 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:12 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/testing/out/_temporary dst=null perm=null
[junit] 09/05/14 18:18:12 INFO mapred.TaskTracker: attempt_200905141817_0001_m_000001_0 0.0% cleanup
[junit] 09/05/14 18:18:12 INFO mapred.TaskTracker: Task attempt_200905141817_0001_m_000001_0 is done.
[junit] 09/05/14 18:18:12 INFO mapred.TaskTracker: reported output size for attempt_200905141817_0001_m_000001_0 was 0
[junit] 09/05/14 18:18:12 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/05/14 18:18:12 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/14 18:18:12 INFO util.ProcessTree: Killing all processes in the process group 11237 with SIGTERM. Exit code 1
[junit] 09/05/14 18:18:13 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/14 18:18:13 INFO util.ProcessTree: Killing process group11147 with SIGKILL. Exit code 1
[junit] 09/05/14 18:18:13 INFO mapred.DefaultTaskController: Process exited with exit code:0
[junit] 09/05/14 18:18:13 INFO mapred.JvmManager: JVM : jvm_200905141817_0001_m_-118297668 exited. Number of tasks it ran: 1
[junit] 09/05/14 18:18:14 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_200905141817_0001/attempt_200905141817_0001_m_000001_0/output/file.out in any of the configured local directories
[junit] 09/05/14 18:18:14 INFO mapred.JobInProgress: Task 'attempt_200905141817_0001_m_000001_0' has completed task_200905141817_0001_m_000001 successfully.
[junit] 09/05/14 18:18:14 INFO mapred.JobInProgress: Job job_200905141817_0001 has completed successfully.
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /testing/out/_logs/history/localhost_1242325070207_job_200905141817_0001_hudson_streamjob5057363101893886081.jar. blk_-7463589363016395078_1008
[junit] 09/05/14 18:18:14 INFO datanode.DataNode: Receiving block blk_-7463589363016395078_1008 src: /127.0.0.1:48345 dest: /127.0.0.1:60835
[junit] 09/05/14 18:18:14 INFO datanode.DataNode: Receiving block blk_-7463589363016395078_1008 src: /127.0.0.1:54057 dest: /127.0.0.1:32850
[junit] 09/05/14 18:18:14 INFO DataNode.clienttrace: src: /127.0.0.1:54057, dest: /127.0.0.1:32850, bytes: 4570, op: HDFS_WRITE, cliID: DFSClient_332739908, offset: 0, srvID: DS-161937833-67.195.138.9-32850-1242325070006, blockid: blk_-7463589363016395078_1008, duration: 1524420
[junit] 09/05/14 18:18:14 INFO datanode.DataNode: PacketResponder 0 for block blk_-7463589363016395078_1008 terminating
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:32850 is added to blk_-7463589363016395078_1008 size 4570
[junit] 09/05/14 18:18:14 INFO DataNode.clienttrace: src: /127.0.0.1:48345, dest: /127.0.0.1:60835, bytes: 4570, op: HDFS_WRITE, cliID: DFSClient_332739908, offset: 0, srvID: DS-720742920-67.195.138.9-60835-1242325069825, blockid: blk_-7463589363016395078_1008, duration: 3090455
[junit] 09/05/14 18:18:14 INFO datanode.DataNode: PacketResponder 1 for block blk_-7463589363016395078_1008 terminating
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60835 is added to blk_-7463589363016395078_1008 size 4570
[junit] 09/05/14 18:18:14 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /testing/out/_logs/history/localhost_1242325070207_job_200905141817_0001_hudson_streamjob5057363101893886081.jar is closed by DFSClient_332739908
[junit] 09/05/14 18:18:14 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:14 INFO mapred.JobTracker: Removed completed task 'attempt_200905141817_0001_m_000000_0' from 'tracker_host0.foo.com:localhost/127.0.0.1:33710'
[junit] 09/05/14 18:18:14 INFO mapred.JobTracker: Removed completed task 'attempt_200905141817_0001_m_000001_0' from 'tracker_host0.foo.com:localhost/127.0.0.1:33710'
[junit] 09/05/14 18:18:14 INFO mapred.JobTracker: Removed completed task 'attempt_200905141817_0001_m_000002_0' from 'tracker_host0.foo.com:localhost/127.0.0.1:33710'
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2432813623774701100 is added to invalidSet of 127.0.0.1:32850
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2432813623774701100 is added to invalidSet of 127.0.0.1:60835
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2367621418724563561 is added to invalidSet of 127.0.0.1:32850
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2367621418724563561 is added to invalidSet of 127.0.0.1:60835
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1765334416104377583 is added to invalidSet of 127.0.0.1:60835
[junit] 09/05/14 18:18:14 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1765334416104377583 is added to invalidSet of 127.0.0.1:32850
[junit] 09/05/14 18:18:14 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:14 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:14 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_200905141817_0001
[junit] 09/05/14 18:18:14 INFO mapred.TaskRunner: attempt_200905141817_0001_m_000000_0 done; removing files.
[junit] 09/05/14 18:18:14 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/user/hudson/build/contrib/streaming/test/system/job_200905141817_0001 dst=null perm=null
[junit] 09/05/14 18:18:14 INFO mapred.IndexCache: Map ID attempt_200905141817_0001_m_000000_0 not found in cache
[junit] 09/05/14 18:18:14 INFO mapred.TaskRunner: attempt_200905141817_0001_m_000001_0 done; removing files.
[junit] 09/05/14 18:18:14 INFO mapred.IndexCache: Map ID attempt_200905141817_0001_m_000001_0 not found in cache
[junit] 09/05/14 18:18:15 INFO streaming.StreamJob: Job complete: job_200905141817_0001
[junit] 09/05/14 18:18:15 INFO streaming.StreamJob: Output: /testing/out
[junit] 09/05/14 18:18:15 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/testing/out dst=null perm=null
[junit] 09/05/14 18:18:15 INFO mapred.TestMiniMRWithDFS: File list[0]: hdfs://localhost:35595/testing/out/part-00000
[junit] 09/05/14 18:18:15 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/testing/out/part-00000 dst=null perm=null
[junit] 09/05/14 18:18:15 INFO DataNode.clienttrace: src: /127.0.0.1:60835, dest: /127.0.0.1:48347, bytes: 12, op: HDFS_READ, cliID: DFSClient_332739908, offset: 0, srvID: DS-720742920-67.195.138.9-60835-1242325069825, blockid: blk_7209758248774497331_1008, duration: 267048
[junit] 09/05/14 18:18:15 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-4350948511064990856 is added to invalidSet of 127.0.0.1:60835
[junit] 09/05/14 18:18:15 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-4350948511064990856 is added to invalidSet of 127.0.0.1:32850
[junit] 09/05/14 18:18:15 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-7463589363016395078 is added to invalidSet of 127.0.0.1:32850
[junit] 09/05/14 18:18:15 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-7463589363016395078 is added to invalidSet of 127.0.0.1:60835
[junit] 09/05/14 18:18:15 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_7209758248774497331 is added to invalidSet of 127.0.0.1:32850
[junit] 09/05/14 18:18:15 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_7209758248774497331 is added to invalidSet of 127.0.0.1:60835
[junit] 09/05/14 18:18:15 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:15 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:15 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/testing/out dst=null perm=null
[junit] 09/05/14 18:18:15 INFO mapred.TaskTracker: Shutting down: Map-events fetcher for all reduce tasks on tracker_host0.foo.com:localhost/127.0.0.1:33710
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping server on 33710
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 2 on 33710: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping IPC Server listener on 33710
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 1 on 33710: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 3 on 33710: exiting
[junit] 09/05/14 18:18:15 INFO mapred.TaskTracker: Shutting down StatusHttpServer
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 0 on 33710: exiting
[junit] 09/05/14 18:18:15 INFO mapred.TaskTracker: Interrupted. Closing down.
[junit] 09/05/14 18:18:15 INFO mapred.TaskTracker: Shutting down: Map-events fetcher for all reduce tasks on tracker_host1.foo.com:localhost/127.0.0.1:56787
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping server on 56787
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 0 on 56787: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 1 on 56787: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 2 on 56787: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping IPC Server listener on 56787
[junit] 09/05/14 18:18:15 INFO mapred.TaskTracker: Shutting down StatusHttpServer
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 3 on 56787: exiting
[junit] 09/05/14 18:18:15 INFO mapred.TaskTracker: Interrupted. Closing down.
[junit] 09/05/14 18:18:15 INFO mapred.JobTracker: Stopping infoServer
[junit] 09/05/14 18:18:15 INFO mapred.JobTracker: Stopping interTrackerServer
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping server on 55962
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 0 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 2 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 7 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 6 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 9 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 8 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO mapred.JobTracker: Stopped interTrackerServer
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 5 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO mapred.JobTracker: Stopping expireTrackers
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping IPC Server listener on 55962
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 4 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 1 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO mapred.JobTracker: Stopping retirer
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 3 on 55962: exiting
[junit] 09/05/14 18:18:15 INFO mapred.EagerTaskInitializationListener: Stopping Job Init Manager thread
[junit] 09/05/14 18:18:15 INFO mapred.EagerTaskInitializationListener: JobInitManagerThread interrupted.
[junit] 09/05/14 18:18:15 INFO mapred.EagerTaskInitializationListener: Shutting down thread pool
[junit] 09/05/14 18:18:15 INFO mapred.JobTracker: Stopping expireLaunchingTasks
[junit] 09/05/14 18:18:15 INFO mapred.JobTracker: stopped all jobtracker services
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping server on 38063
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 0 on 38063: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping IPC Server listener on 38063
[junit] 09/05/14 18:18:15 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 1 on 38063: exiting
[junit] 09/05/14 18:18:15 INFO ipc.Server: IPC Server handler 2 on 38063: exiting
[junit] 09/05/14 18:18:15 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 09/05/14 18:18:15 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:32850, storageID=DS-161937833-67.195.138.9-32850-1242325070006, infoPort=58629, ipcPort=38063):DataXceiveServer: java.nio.channels.AsynchronousCloseException
[junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185)
[junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152)
[junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:130)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 09/05/14 18:18:15 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:60835 to delete blk_2367621418724563561_1004 blk_7209758248774497331_1008 blk_-4350948511064990856_1007 blk_1765334416104377583_1005 blk_-2432813623774701100_1003 blk_-7463589363016395078_1008
[junit] 09/05/14 18:18:16 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 09/05/14 18:18:16 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 09/05/14 18:18:16 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:32850, storageID=DS-161937833-67.195.138.9-32850-1242325070006, infoPort=58629, ipcPort=38063):Finishing DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/data/data4/current'}
[junit] 09/05/14 18:18:16 INFO ipc.Server: Stopping server on 38063
[junit] 09/05/14 18:18:16 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 09/05/14 18:18:16 INFO ipc.Server: Stopping server on 54037
[junit] 09/05/14 18:18:16 INFO ipc.Server: IPC Server handler 0 on 54037: exiting
[junit] 09/05/14 18:18:16 INFO ipc.Server: Stopping IPC Server listener on 54037
[junit] 09/05/14 18:18:16 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 09/05/14 18:18:16 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/14 18:18:16 INFO ipc.Server: IPC Server handler 2 on 54037: exiting
[junit] 09/05/14 18:18:16 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:60835, storageID=DS-720742920-67.195.138.9-60835-1242325069825, infoPort=43419, ipcPort=54037):DataXceiveServer: java.nio.channels.AsynchronousCloseException
[junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185)
[junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152)
[junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:130)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit]
[junit] 09/05/14 18:18:16 INFO ipc.Server: IPC Server handler 1 on 54037: exiting
[junit] 09/05/14 18:18:16 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:60835, storageID=DS-720742920-67.195.138.9-60835-1242325069825, infoPort=43419, ipcPort=54037):Finishing DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data1/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/data/data2/current'}
[junit] 09/05/14 18:18:16 INFO ipc.Server: Stopping server on 54037
[junit] 09/05/14 18:18:16 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 09/05/14 18:18:16 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 09/05/14 18:18:17 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/14 18:18:17 INFO util.ProcessTree: Killing process group11237 with SIGKILL. Exit code 1
[junit] 09/05/14 18:18:17 INFO mapred.DefaultTaskController: Process exited with exit code:0
[junit] 09/05/14 18:18:17 INFO mapred.JvmManager: JVM : jvm_200905141817_0001_m_-1010643465 exited. Number of tasks it ran: 1
[junit] 09/05/14 18:18:17 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 09/05/14 18:18:17 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 09/05/14 18:18:17 INFO namenode.FSNamesystem: Number of transactions: 51 Total time for transactions(ms): 7Number of transactions batched in Syncs: 1 Number of syncs: 34 SyncTimes(ms): 28 8
[junit] 09/05/14 18:18:17 WARN namenode.DecommissionManager: Monitor interrupted: java.lang.InterruptedException: sleep interrupted
[junit] 09/05/14 18:18:17 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/05/14 18:18:17 INFO ipc.Server: Stopping server on 35595
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 2 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 0 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 1 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 3 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 4 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 5 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 6 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 7 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 9 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: IPC Server handler 8 on 35595: exiting
[junit] 09/05/14 18:18:17 INFO ipc.Server: Stopping IPC Server listener on 35595
[junit] 09/05/14 18:18:17 INFO ipc.Server: Stopping IPC Server Responder
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 29.492 sec
[junit] Running org.apache.hadoop.typedbytes.TestIO
[junit] 09/05/14 18:18:18 WARN conf.Configuration: DEPRECATED: hadoop-site.xml found in the classpath. Usage of hadoop-site.xml is deprecated. Instead use core-site.xml, mapred-site.xml and hdfs-site.xml to override properties of core-default.xml, mapred-default.xml and hdfs-default.xml respectively
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.255 sec
[junit] Running org.apache.hadoop.typedbytes.TestTypedBytesWritable
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.19 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1049: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1022: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build.xml :48: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/streaming/build.xml :42: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build-contrib.xml :250: Tests failed!
Total time: 244 minutes 3 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...