See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/843/changes
Changes:
[szetszwo] HADOOP-5867. Fix javac warnings found in NNBench and
NNBenchWithoutMR. Konstantin Boudnik
[shv] HADOOP-5687. NameNode throws NPE if fs.default.name is the default value.
Contributed by Philip Zeyliger.
[rangadi] HADOOP-5782. Revert a few formatting changes introduced in
HADOOP-5015.
(Suresh Srinivas via rangadi)
[tomwhite] HADOOP-4829. Allow FileSystem shutdown hook to be disabled.
Contributed by Todd Lipcon.
[tomwhite] HADOOP-5839. Fix EC2 scripts to allow remote job submission.
Contributed by Joydeep Sen Sarma.
------------------------------------------
[...truncated 524510 lines...]
[junit] 09/05/22 16:54:24 INFO mapred.TaskTracker: Trying to launch :
attempt_200905221654_0001_m_000000_0
[junit] 09/05/22 16:54:24 INFO mapred.TaskTracker: In TaskLauncher, current
free slots : 2 and trying to launch attempt_200905221654_0001_m_000000_0
[junit] 09/05/22 16:54:24 INFO mapred.JvmManager: In JvmRunner constructed
JVM ID: jvm_200905221654_0001_m_1723760811
[junit] 09/05/22 16:54:24 INFO mapred.JvmManager: JVM Runner
jvm_200905221654_0001_m_1723760811 spawned.
[junit] 09/05/22 16:54:25 INFO mapred.TaskTracker: JVM with ID:
jvm_200905221654_0001_m_1723760811 given task:
attempt_200905221654_0001_m_000000_0
[junit] 09/05/22 16:54:25 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=open src=/testing/in/part0 dst=null
perm=null
[junit] 09/05/22 16:54:25 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/22 16:54:25 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/22 16:54:25 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=mkdirs
src=/testing/out/_temporary/_attempt_200905221654_0001_m_000000_0
dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/05/22 16:54:25 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/22 16:54:25 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/22 16:54:26 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/22 16:54:26 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=create
src=/testing/out/_temporary/_attempt_200905221654_0001_m_000000_0/part-00000
dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/05/22 16:54:26 INFO DataNode.clienttrace: src: /127.0.0.1:33660,
dest: /127.0.0.1:33566, bytes: 19, op: HDFS_READ, cliID:
DFSClient_attempt_200905221654_0001_m_000000_0, offset: 0, srvID:
DS-1376956328-67.195.138.9-33660-1243011248728, blockid:
blk_5204446342253021769_1002, duration: 242235
[junit] 09/05/22 16:54:26 INFO mapred.TaskTracker:
attempt_200905221654_0001_m_000000_0 0.0%
[junit] 09/05/22 16:54:26 INFO hdfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/testing/out/_temporary/_attempt_200905221654_0001_m_000000_0/part-00000.
blk_-2648097797812531342_1008
[junit] 09/05/22 16:54:26 INFO datanode.DataNode: Receiving block
blk_-2648097797812531342_1008 src: /127.0.0.1:33567 dest: /127.0.0.1:33660
[junit] 09/05/22 16:54:26 INFO datanode.DataNode: Receiving block
blk_-2648097797812531342_1008 src: /127.0.0.1:52562 dest: /127.0.0.1:38212
[junit] 09/05/22 16:54:26 INFO DataNode.clienttrace: src: /127.0.0.1:52562,
dest: /127.0.0.1:38212, bytes: 8, op: HDFS_WRITE, cliID:
DFSClient_attempt_200905221654_0001_m_000000_0, offset: 0, srvID:
DS-1358606271-67.195.138.9-38212-1243011249327, blockid:
blk_-2648097797812531342_1008, duration: 2383026
[junit] 09/05/22 16:54:26 INFO datanode.DataNode: PacketResponder 0 for
block blk_-2648097797812531342_1008 terminating
[junit] 09/05/22 16:54:26 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38212 is added to
blk_-2648097797812531342_1008 size 8
[junit] 09/05/22 16:54:26 INFO DataNode.clienttrace: src: /127.0.0.1:33567,
dest: /127.0.0.1:33660, bytes: 8, op: HDFS_WRITE, cliID:
DFSClient_attempt_200905221654_0001_m_000000_0, offset: 0, srvID:
DS-1376956328-67.195.138.9-33660-1243011248728, blockid:
blk_-2648097797812531342_1008, duration: 3340623
[junit] 09/05/22 16:54:26 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33660 is added to
blk_-2648097797812531342_1008 size 8
[junit] 09/05/22 16:54:26 INFO datanode.DataNode: PacketResponder 1 for
block blk_-2648097797812531342_1008 terminating
[junit] 09/05/22 16:54:26 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/22 16:54:26 INFO hdfs.StateChange: DIR*
NameSystem.completeFile: file
/testing/out/_temporary/_attempt_200905221654_0001_m_000000_0/part-00000 is
closed by DFSClient_attempt_200905221654_0001_m_000000_0
[junit] 09/05/22 16:54:26 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/22 16:54:26 INFO mapred.TaskTracker: Task
attempt_200905221654_0001_m_000000_0 is in commit-pending, task
state:COMMIT_PENDING
[junit] 09/05/22 16:54:26 INFO mapred.TaskTracker:
attempt_200905221654_0001_m_000000_0 0.0%
[junit] 09/05/22 16:54:27 INFO mapred.TaskTracker: Received commit task
action for attempt_200905221654_0001_m_000000_0
[junit] 09/05/22 16:54:28 WARN util.ProcessTree: Error executing shell
command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/22 16:54:28 INFO util.ProcessTree: Killing process group20056
with SIGKILL. Exit code 1
[junit] 09/05/22 16:54:28 INFO mapred.DefaultTaskController: Process exited
with exit code:0
[junit] 09/05/22 16:54:28 INFO mapred.JvmManager: JVM :
jvm_200905221654_0001_m_-2139567683 exited. Number of tasks it ran: 1
[junit] 09/05/22 16:54:28 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus
src=/testing/out/_temporary/_attempt_200905221654_0001_m_000000_0
dst=null perm=null
[junit] 09/05/22 16:54:28 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/22 16:54:28 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/22 16:54:28 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/22 16:54:28 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=rename
src=/testing/out/_temporary/_attempt_200905221654_0001_m_000000_0/part-00000
dst=/testing/out/part-00000 perm=hudson:supergroup:rw-r--r--
[junit] 09/05/22 16:54:28 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/22 16:54:28 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/22 16:54:28 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=delete
src=/testing/out/_temporary/_attempt_200905221654_0001_m_000000_0
dst=null perm=null
[junit] 09/05/22 16:54:28 INFO mapred.TaskTracker:
attempt_200905221654_0001_m_000000_0 0.667% Records R/W=1/1 > sort
[junit] 09/05/22 16:54:28 INFO mapred.TaskTracker: Task
attempt_200905221654_0001_m_000000_0 is done.
[junit] 09/05/22 16:54:28 INFO mapred.TaskTracker: reported output size for
attempt_200905221654_0001_m_000000_0 was 0
[junit] 09/05/22 16:54:28 INFO mapred.TaskTracker: addFreeSlot : current
free slots : 2
[junit] 09/05/22 16:54:28 WARN util.ProcessTree: Error executing shell
command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/22 16:54:28 INFO util.ProcessTree: Killing all processes in
the process group 20130 with SIGTERM. Exit code 1
[junit] 09/05/22 16:54:30 INFO mapred.TaskTracker:
org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find
taskTracker/jobcache/job_200905221654_0001/attempt_200905221654_0001_m_000000_0/output/file.out
in any of the configured local directories
[junit] 09/05/22 16:54:30 INFO mapred.JobInProgress: Task
'attempt_200905221654_0001_m_000000_0' has completed
task_200905221654_0001_m_000000 successfully.
[junit] 09/05/22 16:54:30 INFO mapred.JobTracker: Adding task
'attempt_200905221654_0001_m_000001_0' to tip task_200905221654_0001_m_000001,
for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:47270'
[junit] 09/05/22 16:54:30 INFO mapred.TaskTracker: LaunchTaskAction
(registerTask): attempt_200905221654_0001_m_000001_0 task's state:UNASSIGNED
[junit] 09/05/22 16:54:30 INFO mapred.TaskTracker: Trying to launch :
attempt_200905221654_0001_m_000001_0
[junit] 09/05/22 16:54:30 INFO mapred.TaskTracker: In TaskLauncher, current
free slots : 2 and trying to launch attempt_200905221654_0001_m_000001_0
[junit] 09/05/22 16:54:30 INFO mapred.JvmManager: In JvmRunner constructed
JVM ID: jvm_200905221654_0001_m_1030757806
[junit] 09/05/22 16:54:30 INFO mapred.JvmManager: JVM Runner
jvm_200905221654_0001_m_1030757806 spawned.
[junit] 09/05/22 16:54:31 INFO mapred.TaskTracker: JVM with ID:
jvm_200905221654_0001_m_1030757806 given task:
attempt_200905221654_0001_m_000001_0
[junit] 09/05/22 16:54:31 INFO streaming.StreamJob: map 100% reduce 0%
[junit] 09/05/22 16:54:31 INFO mapred.TaskTracker:
attempt_200905221654_0001_m_000001_0 0.0%
[junit] 09/05/22 16:54:31 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/22 16:54:31 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/22 16:54:31 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=delete src=/testing/out/_temporary dst=null
perm=null
[junit] 09/05/22 16:54:31 INFO mapred.TaskTracker:
attempt_200905221654_0001_m_000001_0 0.0% cleanup > map
[junit] 09/05/22 16:54:31 INFO mapred.TaskTracker: Task
attempt_200905221654_0001_m_000001_0 is done.
[junit] 09/05/22 16:54:31 INFO mapred.TaskTracker: reported output size for
attempt_200905221654_0001_m_000001_0 was 0
[junit] 09/05/22 16:54:31 INFO mapred.TaskTracker: addFreeSlot : current
free slots : 2
[junit] 09/05/22 16:54:31 WARN util.ProcessTree: Error executing shell
command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/22 16:54:31 INFO util.ProcessTree: Killing all processes in
the process group 20220 with SIGTERM. Exit code 1
[junit] 09/05/22 16:54:33 WARN util.ProcessTree: Error executing shell
command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process
[junit]
[junit] 09/05/22 16:54:33 INFO util.ProcessTree: Killing process group20130
with SIGKILL. Exit code 1
[junit] 09/05/22 16:54:33 INFO mapred.DefaultTaskController: Process exited
with exit code:0
[junit] 09/05/22 16:54:33 INFO mapred.JvmManager: JVM :
jvm_200905221654_0001_m_1723760811 exited. Number of tasks it ran: 1
[junit] 09/05/22 16:54:33 INFO mapred.TaskTracker:
org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find
taskTracker/jobcache/job_200905221654_0001/attempt_200905221654_0001_m_000001_0/output/file.out
in any of the configured local directories
[junit] 09/05/22 16:54:33 INFO mapred.JobInProgress: Task
'attempt_200905221654_0001_m_000001_0' has completed
task_200905221654_0001_m_000001 successfully.
[junit] 09/05/22 16:54:33 INFO mapred.JobInProgress: Job
job_200905221654_0001 has completed successfully.
[junit] 09/05/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/testing/out/_logs/history/localhost_1243011249616_job_200905221654_0001_hudson_streamjob8674154162759242251.jar.
blk_-3868513767287327748_1008
[junit] 09/05/22 16:54:33 INFO datanode.DataNode: Receiving block
blk_-3868513767287327748_1008 src: /127.0.0.1:33574 dest: /127.0.0.1:33660
[junit] 09/05/22 16:54:33 INFO datanode.DataNode: Receiving block
blk_-3868513767287327748_1008 src: /127.0.0.1:52569 dest: /127.0.0.1:38212
[junit] 09/05/22 16:54:33 INFO DataNode.clienttrace: src: /127.0.0.1:52569,
dest: /127.0.0.1:38212, bytes: 4676, op: HDFS_WRITE, cliID:
DFSClient_-1852807403, offset: 0, srvID:
DS-1358606271-67.195.138.9-38212-1243011249327, blockid:
blk_-3868513767287327748_1008, duration: 2306734
[junit] 09/05/22 16:54:33 INFO datanode.DataNode: PacketResponder 0 for
block blk_-3868513767287327748_1008 terminating
[junit] 09/05/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38212 is added to
blk_-3868513767287327748_1008 size 4676
[junit] 09/05/22 16:54:33 INFO DataNode.clienttrace: src: /127.0.0.1:33574,
dest: /127.0.0.1:33660, bytes: 4676, op: HDFS_WRITE, cliID:
DFSClient_-1852807403, offset: 0, srvID:
DS-1376956328-67.195.138.9-33660-1243011248728, blockid:
blk_-3868513767287327748_1008, duration: 3399114
[junit] 09/05/22 16:54:33 INFO datanode.DataNode: PacketResponder 1 for
block blk_-3868513767287327748_1008 terminating
[junit] 09/05/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33660 is added to
blk_-3868513767287327748_1008 size 4676
[junit] 09/05/22 16:54:33 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/22 16:54:33 INFO hdfs.StateChange: DIR*
NameSystem.completeFile: file
/testing/out/_logs/history/localhost_1243011249616_job_200905221654_0001_hudson_streamjob8674154162759242251.jar
is closed by DFSClient_-1852807403
[junit] 09/05/22 16:54:33 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/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_2276800065836294866 is added to invalidSet of
127.0.0.1:33660
[junit] 09/05/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_2276800065836294866 is added to invalidSet of
127.0.0.1:38212
[junit] 09/05/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-1543907191395377531 is added to invalidSet of
127.0.0.1:33660
[junit] 09/05/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-1543907191395377531 is added to invalidSet of
127.0.0.1:38212
[junit] 09/05/22 16:54:33 INFO mapred.JobTracker: Removed completed task
'attempt_200905221654_0001_m_000000_0' from
'tracker_host0.foo.com:localhost/127.0.0.1:47270'
[junit] 09/05/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_6084820421728020198 is added to invalidSet of
127.0.0.1:33660
[junit] 09/05/22 16:54:33 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_6084820421728020198 is added to invalidSet of
127.0.0.1:38212
[junit] 09/05/22 16:54:33 INFO mapred.JobTracker: Removed completed task
'attempt_200905221654_0001_m_000001_0' from
'tracker_host0.foo.com:localhost/127.0.0.1:47270'
[junit] 09/05/22 16:54:33 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/22 16:54:33 INFO mapred.JobTracker: Removed completed task
'attempt_200905221654_0001_m_000002_0' from
'tracker_host0.foo.com:localhost/127.0.0.1:47270'
[junit] 09/05/22 16:54:33 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200905221654_0001
[junit] 09/05/22 16:54:33 INFO mapred.TaskRunner:
attempt_200905221654_0001_m_000001_0 done; removing files.
[junit] 09/05/22 16:54:33 INFO mapred.IndexCache: Map ID
attempt_200905221654_0001_m_000001_0 not found in cache
[junit] 09/05/22 16:54:33 INFO mapred.TaskRunner:
attempt_200905221654_0001_m_000000_0 done; removing files.
[junit] 09/05/22 16:54:33 INFO mapred.IndexCache: Map ID
attempt_200905221654_0001_m_000000_0 not found in cache
[junit] 09/05/22 16:54:33 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/22 16:54:33 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=delete
src=/user/hudson/build/contrib/streaming/test/system/job_200905221654_0001
dst=null perm=null
[junit] 09/05/22 16:54:34 INFO streaming.StreamJob: Job complete:
job_200905221654_0001
[junit] 09/05/22 16:54:34 INFO streaming.StreamJob: Output: /testing/out
[junit] 09/05/22 16:54:34 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus src=/testing/out dst=null
perm=null
[junit] 09/05/22 16:54:34 INFO mapred.TestMiniMRWithDFS: File list[0]:
hdfs://localhost:39910/testing/out/part-00000
[junit] 09/05/22 16:54:34 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/22 16:54:34 INFO DataNode.clienttrace: src: /127.0.0.1:33660,
dest: /127.0.0.1:33576, bytes: 12, op: HDFS_READ, cliID: DFSClient_-1852807403,
offset: 0, srvID: DS-1376956328-67.195.138.9-33660-1243011248728, blockid:
blk_-2648097797812531342_1008, duration: 288149
[junit] 09/05/22 16:54:34 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-4927906180940839246 is added to invalidSet of
127.0.0.1:33660
[junit] 09/05/22 16:54:34 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-4927906180940839246 is added to invalidSet of
127.0.0.1:38212
[junit] 09/05/22 16:54:34 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-3868513767287327748 is added to invalidSet of
127.0.0.1:38212
[junit] 09/05/22 16:54:34 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-3868513767287327748 is added to invalidSet of
127.0.0.1:33660
[junit] 09/05/22 16:54:34 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-2648097797812531342 is added to invalidSet of
127.0.0.1:38212
[junit] 09/05/22 16:54:34 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-2648097797812531342 is added to invalidSet of
127.0.0.1:33660
[junit] 09/05/22 16:54:34 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/22 16:54:34 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:33660
to delete blk_6084820421728020198_1005 blk_-1543907191395377531_1004
blk_-3868513767287327748_1008 blk_-2648097797812531342_1008
blk_2276800065836294866_1003 blk_-4927906180940839246_1007
[junit] 09/05/22 16:54:34 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/22 16:54:34 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=delete src=/testing/out dst=null
perm=null
[junit] 09/05/22 16:54:34 INFO mapred.TaskTracker: Shutting down:
Map-events fetcher for all reduce tasks on
tracker_host0.foo.com:localhost/127.0.0.1:47270
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping server on 47270
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 1 on 47270:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 0 on 47270:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping IPC Server listener on
47270
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 2 on 47270:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 3 on 47270:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/22 16:54:34 INFO mapred.TaskTracker: Shutting down
StatusHttpServer
[junit] 09/05/22 16:54:34 INFO mapred.TaskTracker: Interrupted. Closing
down.
[junit] 09/05/22 16:54:34 INFO mapred.TaskTracker: Shutting down:
Map-events fetcher for all reduce tasks on
tracker_host1.foo.com:localhost/127.0.0.1:52778
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping server on 52778
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 0 on 52778:
exiting
[junit] 09/05/22 16:54:34 INFO mapred.TaskTracker: Shutting down
StatusHttpServer
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 1 on 52778:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 3 on 52778:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping IPC Server listener on
52778
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 2 on 52778:
exiting
[junit] 09/05/22 16:54:34 INFO mapred.TaskTracker: Interrupted. Closing
down.
[junit] 09/05/22 16:54:34 INFO mapred.JobTracker: Stopping infoServer
[junit] 09/05/22 16:54:34 INFO mapred.JobTracker: Stopping
interTrackerServer
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping server on 59952
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping IPC Server listener on
59952
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 6 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 8 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 2 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 7 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 0 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 5 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO mapred.JobTracker: Stopped interTrackerServer
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 4 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO mapred.JobTracker: Stopping expireTrackers
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 3 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO mapred.JobTracker: Stopping retirer
[junit] 09/05/22 16:54:34 INFO mapred.EagerTaskInitializationListener:
Stopping Job Init Manager thread
[junit] 09/05/22 16:54:34 INFO mapred.EagerTaskInitializationListener:
JobInitManagerThread interrupted.
[junit] 09/05/22 16:54:34 INFO mapred.EagerTaskInitializationListener:
Shutting down thread pool
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 1 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO ipc.Server: IPC Server handler 9 on 59952:
exiting
[junit] 09/05/22 16:54:34 INFO mapred.JobTracker: Stopping
expireLaunchingTasks
[junit] 09/05/22 16:54:34 INFO mapred.JobTracker: stopped all jobtracker
services
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 09/05/22 16:54:35 INFO ipc.Server: Stopping server on 54392
[junit] 09/05/22 16:54:35 INFO ipc.Server: Stopping IPC Server listener on
54392
[junit] 09/05/22 16:54:35 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/22 16:54:35 INFO ipc.Server: IPC Server handler 1 on 54392:
exiting
[junit] 09/05/22 16:54:35 INFO ipc.Server: IPC Server handler 2 on 54392:
exiting
[junit] 09/05/22 16:54:35 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 1
[junit] 09/05/22 16:54:35 INFO ipc.Server: IPC Server handler 0 on 54392:
exiting
[junit] 09/05/22 16:54:35 WARN datanode.DataNode:
DatanodeRegistration(127.0.0.1:38212,
storageID=DS-1358606271-67.195.138.9-38212-1243011249327, infoPort=34793,
ipcPort=54392):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/22 16:54:35 INFO datanode.DataBlockScanner: Exiting
DataBlockScanner thread.
[junit] 09/05/22 16:54:35 INFO datanode.DataNode: Deleting block
blk_-4927906180940839246_1007 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data2/current/blk_-4927906180940839246
[junit] 09/05/22 16:54:35 INFO datanode.DataNode: Deleting block
blk_-3868513767287327748_1008 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data2/current/blk_-3868513767287327748
[junit] 09/05/22 16:54:35 INFO datanode.DataNode: Deleting block
blk_-2648097797812531342_1008 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data1/current/blk_-2648097797812531342
[junit] 09/05/22 16:54:35 INFO datanode.DataNode: Deleting block
blk_-1543907191395377531_1004 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data2/current/blk_-1543907191395377531
[junit] 09/05/22 16:54:35 INFO datanode.DataNode: Deleting block
blk_2276800065836294866_1003 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data1/current/blk_2276800065836294866
[junit] 09/05/22 16:54:35 INFO datanode.DataNode: Deleting block
blk_6084820421728020198_1005 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data1/current/blk_6084820421728020198
[junit] 09/05/22 16:54:36 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 0
[junit] 09/05/22 16:54:36 INFO datanode.DataNode:
DatanodeRegistration(127.0.0.1:38212,
storageID=DS-1358606271-67.195.138.9-38212-1243011249327, infoPort=34793,
ipcPort=54392):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/22 16:54:36 INFO ipc.Server: Stopping server on 54392
[junit] 09/05/22 16:54:36 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 09/05/22 16:54:36 INFO ipc.Server: Stopping server on 52542
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 2 on 52542:
exiting
[junit] 09/05/22 16:54:36 WARN datanode.DataNode:
DatanodeRegistration(127.0.0.1:33660,
storageID=DS-1376956328-67.195.138.9-33660-1243011248728, infoPort=39783,
ipcPort=52542):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/22 16:54:36 INFO ipc.Server: IPC Server handler 0 on 52542:
exiting
[junit] 09/05/22 16:54:36 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 1
[junit] 09/05/22 16:54:36 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/22 16:54:36 INFO ipc.Server: Stopping IPC Server listener on
52542
[junit] 09/05/22 16:54:36 INFO datanode.DataBlockScanner: Exiting
DataBlockScanner thread.
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 1 on 52542:
exiting
[junit] 09/05/22 16:54:36 INFO datanode.DataNode:
DatanodeRegistration(127.0.0.1:33660,
storageID=DS-1376956328-67.195.138.9-33660-1243011248728, infoPort=39783,
ipcPort=52542):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/22 16:54:36 INFO ipc.Server: Stopping server on 52542
[junit] 09/05/22 16:54:36 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 0
[junit] 09/05/22 16:54:36 WARN namenode.DecommissionManager: Monitor
interrupted: java.lang.InterruptedException: sleep interrupted
[junit] 09/05/22 16:54:36 INFO namenode.FSNamesystem: Number of
transactions: 51 Total time for transactions(ms): 9Number of transactions
batched in Syncs: 1 Number of syncs: 34 SyncTimes(ms): 655 339
[junit] 09/05/22 16:54:36 WARN namenode.FSNamesystem: ReplicationMonitor
thread received InterruptedException.java.lang.InterruptedException: sleep
interrupted
[junit] 09/05/22 16:54:36 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/22 16:54:36 INFO ipc.Server: Stopping server on 39910
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 0 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 1 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 2 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: Stopping IPC Server listener on
39910
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 3 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 5 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 9 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 8 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 6 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 7 on 39910:
exiting
[junit] 09/05/22 16:54:36 INFO ipc.Server: IPC Server handler 4 on 39910:
exiting
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 29.754 sec
[junit] Running org.apache.hadoop.typedbytes.TestIO
[junit] 09/05/22 16:54:36 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.248 sec
[junit] Running org.apache.hadoop.typedbytes.TestTypedBytesWritable
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.191 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml
:1046: The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml
:1027: 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: 255 minutes 54 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...
