See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/799/changes
Changes:
[omalley] HADOOP-5437. Fix TestMiniMRDFSSort to properly test jvm-reuse.
(omalley)
------------------------------------------
[...truncated 359857 lines...]
[junit] 09/04/06 15:19:45 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus
src=/user/hudson/signalFileDir-1614380209994480190 dst=null
perm=null
[junit] 09/04/06 15:19:45 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000003_0 1.0% reduce > reduce
[junit] 09/04/06 15:19:45 INFO mapred.TaskTracker: Task
attempt_200904061517_0005_r_000003_0 is done.
[junit] 09/04/06 15:19:45 INFO mapred.TaskTracker: reported output size for
attempt_200904061517_0005_r_000003_0 was 0
[junit] 09/04/06 15:19:45 INFO mapred.TaskTracker: addFreeSlot : current
free slots : 2
[junit] 09/04/06 15:19:45 INFO mapred.JvmManager: JVM :
jvm_200904061517_0005_r_-515460067 exited. Number of tasks it ran: 1
[junit] 09/04/06 15:19:45 INFO mapred.JobInProgress: Task
'attempt_200904061517_0005_r_000002_0' has completed
task_200904061517_0005_r_000002 successfully.
[junit] 09/04/06 15:19:45 INFO mapred.TaskTracker: Received KillTaskAction
for task: attempt_200904061517_0005_r_000002_0
[junit] 09/04/06 15:19:45 INFO mapred.TaskTracker: About to purge task:
attempt_200904061517_0005_r_000002_0
[junit] 09/04/06 15:19:45 INFO mapred.TaskRunner:
attempt_200904061517_0005_r_000002_0 done; removing files.
[junit] 09/04/06 15:19:45 INFO mapred.ControlledMapReduceJob: Waiting till
4 reduce tasks of the job job_200904061517_0005 finish. 1 tasks already got
finished.
[junit] 09/04/06 15:19:45 INFO mapred.JobInProgress: Task
'attempt_200904061517_0005_r_000003_0' has completed
task_200904061517_0005_r_000003 successfully.
[junit] 09/04/06 15:19:45 INFO mapred.TaskTracker: Received KillTaskAction
for task: attempt_200904061517_0005_r_000003_0
[junit] 09/04/06 15:19:45 INFO mapred.TaskTracker: About to purge task:
attempt_200904061517_0005_r_000003_0
[junit] 09/04/06 15:19:45 INFO mapred.TaskRunner:
attempt_200904061517_0005_r_000003_0 done; removing files.
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000000_0 0.083333336% reduce > copy (1 of 4 at 0.00
MB/s) >
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker: Sent out 12 bytes for
reduce: 0 from map: attempt_200904061517_0005_m_000003_0 given 12/8
[junit] 09/04/06 15:19:46 INFO TaskTracker.clienttrace: src:
127.0.0.1:58480, dest: 127.0.0.1:51985, bytes: 12, op: MAPRED_SHUFFLE, cliID:
attempt_200904061517_0005_m_000003_0
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker: Sent out 12 bytes for
reduce: 0 from map: attempt_200904061517_0005_m_000000_0 given 12/8
[junit] 09/04/06 15:19:46 INFO TaskTracker.clienttrace: src:
127.0.0.1:34677, dest: 127.0.0.1:54873, bytes: 12, op: MAPRED_SHUFFLE, cliID:
attempt_200904061517_0005_m_000000_0
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker: Sent out 12 bytes for
reduce: 0 from map: attempt_200904061517_0005_m_000001_0 given 12/8
[junit] 09/04/06 15:19:46 INFO TaskTracker.clienttrace: src:
127.0.0.1:44810, dest: 127.0.0.1:39293, bytes: 12, op: MAPRED_SHUFFLE, cliID:
attempt_200904061517_0005_m_000001_0
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000000_0 0.083333336% reduce > copy (1 of 4 at 0.00
MB/s) >
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000000_0 0.083333336% reduce > copy (1 of 4 at 0.00
MB/s) >
[junit] 09/04/06 15:19:46 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus
src=/user/hudson/signalFileDir-1614380209994480190 dst=null
perm=null
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000000_0 1.0% reduce > reduce
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker: Task
attempt_200904061517_0005_r_000000_0 is done.
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker: reported output size for
attempt_200904061517_0005_r_000000_0 was 0
[junit] 09/04/06 15:19:46 INFO mapred.TaskTracker: addFreeSlot : current
free slots : 2
[junit] 09/04/06 15:19:46 INFO mapred.JvmManager: JVM :
jvm_200904061517_0005_r_-736533374 exited. Number of tasks it ran: 1
[junit] 09/04/06 15:19:46 INFO mapred.ControlledMapReduceJob: Waiting till
4 reduce tasks of the job job_200904061517_0005 finish. 2 tasks already got
finished.
[junit] 09/04/06 15:19:47 INFO mapred.ControlledMapReduceJob: Waiting till
4 reduce tasks of the job job_200904061517_0005 finish. 2 tasks already got
finished.
[junit] 09/04/06 15:19:48 INFO mapred.JobInProgress: Task
'attempt_200904061517_0005_r_000000_0' has completed
task_200904061517_0005_r_000000 successfully.
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker: Received KillTaskAction
for task: attempt_200904061517_0005_r_000000_0
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker: About to purge task:
attempt_200904061517_0005_r_000000_0
[junit] 09/04/06 15:19:48 INFO mapred.TaskRunner:
attempt_200904061517_0005_r_000000_0 done; removing files.
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000001_0 0.25% reduce > copy (3 of 4 at 0.00 MB/s)
>
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker: Sent out 12 bytes for
reduce: 1 from map: attempt_200904061517_0005_m_000001_0 given 12/8
[junit] 09/04/06 15:19:48 INFO TaskTracker.clienttrace: src:
127.0.0.1:44810, dest: 127.0.0.1:39304, bytes: 12, op: MAPRED_SHUFFLE, cliID:
attempt_200904061517_0005_m_000001_0
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000001_0 0.25% reduce > copy (3 of 4 at 0.00 MB/s)
>
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000001_0 0.25% reduce > copy (3 of 4 at 0.00 MB/s)
>
[junit] 09/04/06 15:19:48 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=listStatus
src=/user/hudson/signalFileDir-1614380209994480190 dst=null
perm=null
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker:
attempt_200904061517_0005_r_000001_0 1.0% reduce > reduce
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker: Task
attempt_200904061517_0005_r_000001_0 is done.
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker: reported output size for
attempt_200904061517_0005_r_000001_0 was 0
[junit] 09/04/06 15:19:48 INFO mapred.TaskTracker: addFreeSlot : current
free slots : 2
[junit] 09/04/06 15:19:48 INFO mapred.JvmManager: JVM :
jvm_200904061517_0005_r_-1724513594 exited. Number of tasks it ran: 1
[junit] 09/04/06 15:19:48 INFO mapred.ControlledMapReduceJob: Waiting till
4 reduce tasks of the job job_200904061517_0005 finish. 3 tasks already got
finished.
[junit] 09/04/06 15:19:49 INFO mapred.ControlledMapReduceJob: Waiting till
4 reduce tasks of the job job_200904061517_0005 finish. 3 tasks already got
finished.
[junit] 09/04/06 15:19:50 INFO mapred.JobInProgress: Task
'attempt_200904061517_0005_r_000001_0' has completed
task_200904061517_0005_r_000001 successfully.
[junit] 09/04/06 15:19:50 INFO mapred.JobTracker: Adding task
'attempt_200904061517_0005_m_000004_0' to tip task_200904061517_0005_m_000004,
for tracker 'tracker_host2.foo.com:localhost/127.0.0.1:40850'
[junit] 09/04/06 15:19:50 INFO mapred.TaskTracker: LaunchTaskAction
(registerTask): attempt_200904061517_0005_m_000004_0 task's state:UNASSIGNED
[junit] 09/04/06 15:19:50 INFO mapred.TaskTracker: Trying to launch :
attempt_200904061517_0005_m_000004_0
[junit] 09/04/06 15:19:50 INFO mapred.TaskTracker: Received KillTaskAction
for task: attempt_200904061517_0005_r_000001_0
[junit] 09/04/06 15:19:50 INFO mapred.TaskTracker: In TaskLauncher, current
free slots : 2 and trying to launch attempt_200904061517_0005_m_000004_0
[junit] 09/04/06 15:19:50 INFO mapred.TaskTracker: About to purge task:
attempt_200904061517_0005_r_000001_0
[junit] 09/04/06 15:19:50 INFO mapred.TaskRunner:
attempt_200904061517_0005_r_000001_0 done; removing files.
[junit] 09/04/06 15:19:50 INFO mapred.JvmManager: In JvmRunner constructed
JVM ID: jvm_200904061517_0005_m_-1497891104
[junit] 09/04/06 15:19:50 INFO mapred.JvmManager: JVM Runner
jvm_200904061517_0005_m_-1497891104 spawned.
[junit] 09/04/06 15:19:50 INFO mapred.TaskTracker: JVM with ID:
jvm_200904061517_0005_m_-1497891104 given task:
attempt_200904061517_0005_m_000004_0
[junit] 09/04/06 15:19:50 INFO mapred.ControlledMapReduceJob: Waiting till
4 reduce tasks of the job job_200904061517_0005 finish. 4 tasks already got
finished.
[junit] 09/04/06 15:19:51 INFO mapred.TaskTracker:
attempt_200904061517_0005_m_000004_0 0.0%
[junit] 09/04/06 15:19:51 INFO mapred.TaskTracker:
attempt_200904061517_0005_m_000004_0 0.0% cleanup
[junit] 09/04/06 15:19:51 INFO mapred.TaskTracker: Task
attempt_200904061517_0005_m_000004_0 is done.
[junit] 09/04/06 15:19:51 INFO mapred.TaskTracker: reported output size for
attempt_200904061517_0005_m_000004_0 was 0
[junit] 09/04/06 15:19:51 INFO mapred.TaskTracker: addFreeSlot : current
free slots : 2
[junit] 09/04/06 15:19:51 INFO mapred.JvmManager: JVM :
jvm_200904061517_0005_m_-1497891104 exited. Number of tasks it ran: 1
[junit] 09/04/06 15:19:53 INFO mapred.TaskTracker:
org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find
taskTracker/jobcache/job_200904061517_0005/attempt_200904061517_0005_m_000004_0/output/file.out
in any of the configured local directories
[junit] 09/04/06 15:19:53 INFO mapred.JobInProgress: Task
'attempt_200904061517_0005_m_000004_0' has completed
task_200904061517_0005_m_000004 successfully.
[junit] 09/04/06 15:19:53 INFO mapred.JobInProgress: Job
job_200904061517_0005 has completed successfully.
[junit] 09/04/06 15:19:53 INFO mapred.JobHistory: Recovered job history
filename for job job_200904061517_0005 is
localhost_1239031020650_job_200904061517_0005_hudson_ControlledJob
[junit] 09/04/06 15:19:53 INFO mapred.JobQueuesManager: Job
job_200904061517_0005 submitted to queue Q4 has completed
[junit] 09/04/06 15:19:53 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_m_000000_0' from
'tracker_host2.foo.com:localhost/127.0.0.1:40850'
[junit] 09/04/06 15:19:53 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_m_000004_0' from
'tracker_host2.foo.com:localhost/127.0.0.1:40850'
[junit] 09/04/06 15:19:53 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_m_000005_0' from
'tracker_host2.foo.com:localhost/127.0.0.1:40850'
[junit] 09/04/06 15:19:53 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_r_000001_0' from
'tracker_host2.foo.com:localhost/127.0.0.1:40850'
[junit] 09/04/06 15:19:53 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200904061517_0005
[junit] 09/04/06 15:19:53 INFO mapred.TaskRunner:
attempt_200904061517_0005_m_000000_0 done; removing files.
[junit] 09/04/06 15:19:53 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-7256112353887450039 is added to invalidSet of
127.0.0.1:50850
[junit] 09/04/06 15:19:53 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_-7256112353887450039 is added to invalidSet of
127.0.0.1:59273
[junit] 09/04/06 15:19:53 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_4849319577459835459 is added to invalidSet of
127.0.0.1:59273
[junit] 09/04/06 15:19:53 INFO hdfs.StateChange: BLOCK*
NameSystem.addToInvalidates: blk_4849319577459835459 is added to invalidSet of
127.0.0.1:50850
[junit] 09/04/06 15:19:53 INFO namenode.FSNamesystem: current list of
storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/capacity-scheduler/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/04/06 15:19:53 INFO namenode.FSNamesystem: current list of
storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/capacity-scheduler/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/04/06 15:19:53 INFO mapred.TaskRunner:
attempt_200904061517_0005_m_000004_0 done; removing files.
[junit] 09/04/06 15:19:53 INFO FSNamesystem.audit: ugi=hudson,hudson
ip=/127.0.0.1 cmd=delete
src=/user/hudson/build/contrib/capacity-scheduler/test/system/job_200904061517_0005
dst=null perm=null
[junit] 09/04/06 15:19:53 INFO mapred.IndexCache: Map ID
attempt_200904061517_0005_m_000004_0 not found in cache
[junit] 09/04/06 15:19:53 INFO mapred.ControlledMapReduceJob: Return value
for the job : 0
[junit] 09/04/06 15:19:53 INFO mapred.MiniMRCluster: Waiting for task
tracker tracker_host0.foo.com:localhost/127.0.0.1:48919 to be idle.
[junit] 09/04/06 15:19:53 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:59273
to delete blk_4849319577459835459_1020 blk_-7256112353887450039_1019
[junit] 09/04/06 15:19:54 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_r_000000_0' from
'tracker_host1.foo.com:localhost/127.0.0.1:45984'
[junit] 09/04/06 15:19:54 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200904061517_0005
[junit] 09/04/06 15:19:54 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_m_000001_0' from
'tracker_host4.foo.com:localhost/127.0.0.1:46539'
[junit] 09/04/06 15:19:54 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_r_000002_0' from
'tracker_host4.foo.com:localhost/127.0.0.1:46539'
[junit] 09/04/06 15:19:54 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200904061517_0005
[junit] 09/04/06 15:19:54 INFO mapred.TaskRunner:
attempt_200904061517_0005_m_000001_0 done; removing files.
[junit] 09/04/06 15:19:54 INFO mapred.MiniMRCluster: Waiting for task
tracker tracker_host0.foo.com:localhost/127.0.0.1:48919 to be idle.
[junit] 09/04/06 15:19:54 INFO datanode.DataNode: Deleting block
blk_-7256112353887450039_1019 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/data/data3/current/blk_-7256112353887450039
[junit] 09/04/06 15:19:54 INFO datanode.DataNode: Deleting block
blk_4849319577459835459_1020 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/data/data4/current/blk_4849319577459835459
[junit] 09/04/06 15:19:54 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_m_000002_0' from
'tracker_host0.foo.com:localhost/127.0.0.1:48919'
[junit] 09/04/06 15:19:54 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_r_000003_0' from
'tracker_host0.foo.com:localhost/127.0.0.1:48919'
[junit] 09/04/06 15:19:54 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200904061517_0005
[junit] 09/04/06 15:19:54 INFO mapred.TaskRunner:
attempt_200904061517_0005_m_000002_0 done; removing files.
[junit] 09/04/06 15:19:55 INFO mapred.JobTracker: Removed completed task
'attempt_200904061517_0005_m_000003_0' from
'tracker_host3.foo.com:localhost/127.0.0.1:46022'
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200904061517_0005
[junit] 09/04/06 15:19:55 INFO mapred.TaskRunner:
attempt_200904061517_0005_m_000003_0 done; removing files.
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down:
Map-events fetcher for all reduce tasks on
tracker_host0.foo.com:localhost/127.0.0.1:48919
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping server on 48919
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 0 on 48919:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server listener on
48919
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 3 on 48919:
exiting
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down
StatusHttpServer
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 2 on 48919:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 1 on 48919:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Interrupted. Closing
down.
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down:
Map-events fetcher for all reduce tasks on
tracker_host1.foo.com:localhost/127.0.0.1:45984
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping server on 45984
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 1 on 45984:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 2 on 45984:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 3 on 45984:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 0 on 45984:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server listener on
45984
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down
StatusHttpServer
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Interrupted. Closing
down.
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down:
Map-events fetcher for all reduce tasks on
tracker_host2.foo.com:localhost/127.0.0.1:40850
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping server on 40850
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 0 on 40850:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server listener on
40850
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 1 on 40850:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 2 on 40850:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 3 on 40850:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down
StatusHttpServer
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Interrupted. Closing
down.
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down:
Map-events fetcher for all reduce tasks on
tracker_host3.foo.com:localhost/127.0.0.1:46022
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping server on 46022
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 0 on 46022:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server listener on
46022
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 1 on 46022:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 3 on 46022:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 2 on 46022:
exiting
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down
StatusHttpServer
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Interrupted. Closing
down.
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down:
Map-events fetcher for all reduce tasks on
tracker_host4.foo.com:localhost/127.0.0.1:46539
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping server on 46539
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server listener on
46539
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 3 on 46539:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 1 on 46539:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:55 INFO mapred.TaskTracker: Shutting down
StatusHttpServer
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 2 on 46539:
exiting
[junit] 09/04/06 15:19:55 INFO ipc.Server: IPC Server handler 0 on 46539:
exiting
[junit] 09/04/06 15:19:56 INFO mapred.TaskTracker: Interrupted. Closing
down.
[junit] 09/04/06 15:19:56 INFO mapred.JobTracker: Stopping infoServer
[junit] 09/04/06 15:19:56 INFO mapred.JobTracker: Stopping
interTrackerServer
[junit] 09/04/06 15:19:56 INFO ipc.Server: Stopping server on 50186
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 0 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 1 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 2 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 3 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO mapred.JobTracker: Stopping expireTrackers
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 9 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: Stopping IPC Server listener on
50186
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 5 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO mapred.JobTracker: Stopped interTrackerServer
[junit] 09/04/06 15:19:56 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 6 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 4 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 7 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 8 on 50186:
exiting
[junit] 09/04/06 15:19:56 INFO mapred.JobTracker: Stopping retirer
[junit] 09/04/06 15:19:56 INFO mapred.JobTracker: Stopping
expireLaunchingTasks
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 09/04/06 15:19:56 INFO mapred.JobTracker: stopped all jobtracker
services
[junit] 09/04/06 15:19:56 INFO ipc.Server: Stopping server on 52833
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 1 on 52833:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: Stopping IPC Server listener on
52833
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 2 on 52833:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: IPC Server handler 0 on 52833:
exiting
[junit] 09/04/06 15:19:56 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:56 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 1
[junit] 09/04/06 15:19:56 WARN datanode.DataNode:
DatanodeRegistration(127.0.0.1:59273,
storageID=DS-906237863-67.195.138.9-59273-1239031020453, infoPort=36483,
ipcPort=52833):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/04/06 15:19:56 INFO datanode.DataBlockScanner: Exiting
DataBlockScanner thread.
[junit] 09/04/06 15:19:56 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:50850
to delete blk_4849319577459835459_1020 blk_-7256112353887450039_1019
[junit] 09/04/06 15:19:57 INFO datanode.DataNode: Deleting block
blk_-7256112353887450039_1019 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/data/data1/current/blk_-7256112353887450039
[junit] 09/04/06 15:19:57 INFO datanode.DataNode: Deleting block
blk_4849319577459835459_1020 file
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/data/data2/current/blk_4849319577459835459
[junit] 09/04/06 15:19:57 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 0
[junit] 09/04/06 15:19:57 INFO datanode.DataNode:
DatanodeRegistration(127.0.0.1:59273,
storageID=DS-906237863-67.195.138.9-59273-1239031020453, infoPort=36483,
ipcPort=52833):Finishing DataNode in:
FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/capacity-scheduler/test/data/dfs/data/data4/current'}
[junit] 09/04/06 15:19:57 INFO ipc.Server: Stopping server on 52833
[junit] 09/04/06 15:19:57 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 09/04/06 15:19:57 INFO ipc.Server: Stopping server on 52749
[junit] 09/04/06 15:19:57 INFO ipc.Server: Stopping IPC Server listener on
52749
[junit] 09/04/06 15:19:57 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 1
[junit] 09/04/06 15:19:57 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:57 INFO ipc.Server: IPC Server handler 0 on 52749:
exiting
[junit] 09/04/06 15:19:57 WARN datanode.DataNode:
DatanodeRegistration(127.0.0.1:50850,
storageID=DS-1307162770-67.195.138.9-50850-1239031020227, infoPort=47970,
ipcPort=52749):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/04/06 15:19:57 INFO ipc.Server: IPC Server handler 1 on 52749:
exiting
[junit] 09/04/06 15:19:57 INFO ipc.Server: IPC Server handler 2 on 52749:
exiting
[junit] 09/04/06 15:19:58 INFO datanode.DataBlockScanner: Exiting
DataBlockScanner thread.
[junit] 09/04/06 15:19:58 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 0
[junit] 09/04/06 15:19:58 INFO datanode.DataNode:
DatanodeRegistration(127.0.0.1:50850,
storageID=DS-1307162770-67.195.138.9-50850-1239031020227, infoPort=47970,
ipcPort=52749):Finishing DataNode in:
FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/data/data1/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/capacity-scheduler/test/data/dfs/data/data2/current'}
[junit] 09/04/06 15:19:58 INFO ipc.Server: Stopping server on 52749
[junit] 09/04/06 15:19:58 INFO datanode.DataNode: Waiting for threadgroup
to exit, active threads is 0
[junit] 09/04/06 15:19:58 WARN namenode.FSNamesystem: ReplicationMonitor
thread received InterruptedException.java.lang.InterruptedException: sleep
interrupted
[junit] 09/04/06 15:19:58 WARN namenode.DecommissionManager: Monitor
interrupted: java.lang.InterruptedException: sleep interrupted
[junit] 09/04/06 15:19:58 INFO namenode.FSNamesystem: Number of
transactions: 109 Total time for transactions(ms): 15Number of transactions
batched in Syncs: 4 Number of syncs: 85 SyncTimes(ms): 90 84
[junit] 09/04/06 15:19:58 INFO namenode.FSNamesystem: current list of
storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/capacity-scheduler/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/capacity-scheduler/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 09/04/06 15:19:58 INFO ipc.Server: Stopping server on 60864
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 0 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 6 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: Stopping IPC Server listener on
60864
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 1 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 4 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: Stopping IPC Server Responder
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 3 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 5 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 8 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 7 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 2 on 60864:
exiting
[junit] 09/04/06 15:19:58 INFO ipc.Server: IPC Server handler 9 on 60864:
exiting
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 419.665 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :774:
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/build-contrib.xml
:245: Tests failed!
Total time: 192 minutes 58 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...
