See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/806/
------------------------------------------
[...truncated 451690 lines...]
[junit] 2009-04-13 15:11:05,435 INFO datanode.DataNode
(DataNode.java:startDataNode(317)) - Opened info server at 36979
[junit] 2009-04-13 15:11:05,436 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-04-13 15:11:05,436 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1239641759436 with
interval 21600000
[junit] 2009-04-13 15:11:05,438 INFO http.HttpServer
(HttpServer.java:start(454)) - Jetty bound to port 40950
[junit] 2009-04-13 15:11:05,438 INFO mortbay.log (?:invoke0(?)) -
jetty-6.1.14
[junit] 2009-04-13 15:11:05,506 INFO mortbay.log (?:invoke0(?)) - Started
selectchannelconnec...@localhost:40950
[junit] 2009-04-13 15:11:05,507 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-04-13 15:11:05,508 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=33805
[junit] 2009-04-13 15:11:05,509 INFO ipc.Server (Server.java:run(471)) -
IPC Server Responder: starting
[junit] 2009-04-13 15:11:05,509 INFO ipc.Server (Server.java:run(934)) -
IPC Server handler 2 on 33805: starting
[junit] 2009-04-13 15:11:05,509 INFO ipc.Server (Server.java:run(934)) -
IPC Server handler 1 on 33805: starting
[junit] 2009-04-13 15:11:05,509 INFO ipc.Server (Server.java:run(934)) -
IPC Server handler 0 on 33805: starting
[junit] 2009-04-13 15:11:05,509 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 33805: starting
[junit] 2009-04-13 15:11:05,510 INFO datanode.DataNode
(DataNode.java:startDataNode(396)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:36979, storageID=, infoPort=40950,
ipcPort=33805)
[junit] 2009-04-13 15:11:05,512 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(2077)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:36979 storage
DS-1024826634-67.195.138.9-36979-1239635465511
[junit] 2009-04-13 15:11:05,512 INFO net.NetworkTopology
(NetworkTopology.java:add(328)) - Adding a new node:
/default-rack/127.0.0.1:36979
[junit] 2009-04-13 15:11:05,515 INFO datanode.DataNode
(DataNode.java:register(554)) - New storage id
DS-1024826634-67.195.138.9-36979-1239635465511 is assigned to data-node
127.0.0.1:36979
[junit] 2009-04-13 15:11:05,515 INFO datanode.DataNode
(DataNode.java:run(1214)) - DatanodeRegistration(127.0.0.1:36979,
storageID=DS-1024826634-67.195.138.9-36979-1239635465511, infoPort=40950,
ipcPort=33805)In DataNode.run, data =
FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/data/data1/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/data/data2/current'}
[junit] Starting DataNode 1 with dfs.data.dir:
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/data/data3,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/data/data4
[junit] 2009-04-13 15:11:05,516 INFO datanode.DataNode
(DataNode.java:offerService(696)) - using BLOCKREPORT_INTERVAL of 3600000msec
Initial delay: 0msec
[junit] 2009-04-13 15:11:05,518 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Storage directory
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/data/data3
is not formatted.
[junit] 2009-04-13 15:11:05,519 INFO common.Storage
(DataStorage.java:recoverTransitionRead(124)) - Formatting ...
[junit] 2009-04-13 15:11:05,530 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Storage directory
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/data/data4
is not formatted.
[junit] 2009-04-13 15:11:05,530 INFO common.Storage
(DataStorage.java:recoverTransitionRead(124)) - Formatting ...
[junit] 2009-04-13 15:11:05,566 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-04-13 15:11:05,567 INFO datanode.DataNode
(DataNode.java:startDataNode(317)) - Opened info server at 55551
[junit] 2009-04-13 15:11:05,567 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-04-13 15:11:05,568 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1239640782568 with
interval 21600000
[junit] 2009-04-13 15:11:05,570 INFO http.HttpServer
(HttpServer.java:start(454)) - Jetty bound to port 45660
[junit] 2009-04-13 15:11:05,570 INFO mortbay.log (?:invoke0(?)) -
jetty-6.1.14
[junit] 2009-04-13 15:11:05,575 INFO datanode.DataNode
(DataNode.java:blockReport(925)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-04-13 15:11:05,575 INFO datanode.DataNode
(DataNode.java:offerService(739)) - Starting Periodic block scanner.
[junit] 2009-04-13 15:11:05,639 INFO mortbay.log (?:invoke0(?)) - Started
selectchannelconnec...@localhost:45660
[junit] 2009-04-13 15:11:05,640 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-04-13 15:11:05,641 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=53696
[junit] 2009-04-13 15:11:05,642 INFO ipc.Server (Server.java:run(471)) -
IPC Server Responder: starting
[junit] 2009-04-13 15:11:05,642 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 53696: starting
[junit] 2009-04-13 15:11:05,642 INFO ipc.Server (Server.java:run(934)) -
IPC Server handler 0 on 53696: starting
[junit] 2009-04-13 15:11:05,643 INFO ipc.Server (Server.java:run(934)) -
IPC Server handler 1 on 53696: starting
[junit] 2009-04-13 15:11:05,643 INFO datanode.DataNode
(DataNode.java:startDataNode(396)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:55551, storageID=, infoPort=45660,
ipcPort=53696)
[junit] 2009-04-13 15:11:05,643 INFO ipc.Server (Server.java:run(934)) -
IPC Server handler 2 on 53696: starting
[junit] 2009-04-13 15:11:05,644 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(2077)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:55551 storage
DS-274840152-67.195.138.9-55551-1239635465644
[junit] 2009-04-13 15:11:05,645 INFO net.NetworkTopology
(NetworkTopology.java:add(328)) - Adding a new node:
/default-rack/127.0.0.1:55551
[junit] 2009-04-13 15:11:05,647 INFO datanode.DataNode
(DataNode.java:register(554)) - New storage id
DS-274840152-67.195.138.9-55551-1239635465644 is assigned to data-node
127.0.0.1:55551
[junit] 2009-04-13 15:11:05,648 INFO datanode.DataNode
(DataNode.java:run(1214)) - DatanodeRegistration(127.0.0.1:55551,
storageID=DS-274840152-67.195.138.9-55551-1239635465644, infoPort=45660,
ipcPort=53696)In DataNode.run, data =
FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/data/data4/current'}
[junit] 2009-04-13 15:11:05,654 INFO datanode.DataNode
(DataNode.java:offerService(696)) - using BLOCKREPORT_INTERVAL of 3600000msec
Initial delay: 0msec
[junit] 2009-04-13 15:11:05,679 INFO namenode.FSNamesystem
(FSEditLog.java:processIOError(471)) - current list of storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 2009-04-13 15:11:05,680 INFO namenode.FSNamesystem
(FSEditLog.java:processIOError(471)) - current list of storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 2009-04-13 15:11:05,693 INFO datanode.DataNode
(DataNode.java:blockReport(925)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-04-13 15:11:05,694 INFO datanode.DataNode
(DataNode.java:offerService(739)) - Starting Periodic block scanner.
[junit] 2009-04-13 15:11:05,728 INFO namenode.FSNamesystem
(FSEditLog.java:processIOError(471)) - current list of storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 2009-04-13 15:11:05,728 INFO FSNamesystem.audit
(FSNamesystem.java:logAuditEvent(110)) - ugi=hudson,hudson ip=/127.0.0.1
cmd=create src=/test dst=null perm=hudson:supergroup:rw-r--r--
[junit] 2009-04-13 15:11:05,731 INFO hdfs.StateChange
(FSNamesystem.java:allocateBlock(1474)) - BLOCK* NameSystem.allocateBlock:
/test. blk_6482305749944161008_1001
[junit] 2009-04-13 15:11:05,733 INFO datanode.DataNode
(DataXceiver.java:writeBlock(228)) - Receiving block
blk_6482305749944161008_1001 src: /127.0.0.1:41081 dest: /127.0.0.1:36979
[junit] 2009-04-13 15:11:05,734 INFO datanode.DataNode
(DataXceiver.java:writeBlock(228)) - Receiving block
blk_6482305749944161008_1001 src: /127.0.0.1:57734 dest: /127.0.0.1:55551
[junit] 2009-04-13 15:11:05,736 INFO DataNode.clienttrace
(BlockReceiver.java:lastDataNodeRun(805)) - src: /127.0.0.1:57734, dest:
/127.0.0.1:55551, bytes: 4096, op: HDFS_WRITE, cliID: DFSClient_-1657953501,
offset: 0, srvID: DS-274840152-67.195.138.9-55551-1239635465644, blockid:
blk_6482305749944161008_1001
[junit] 2009-04-13 15:11:05,737 INFO datanode.DataNode
(BlockReceiver.java:lastDataNodeRun(829)) - PacketResponder 0 for block
blk_6482305749944161008_1001 terminating
[junit] 2009-04-13 15:11:05,737 INFO hdfs.StateChange
(FSNamesystem.java:addStoredBlock(3079)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:55551 is added to blk_6482305749944161008_1001 size
4096
[junit] 2009-04-13 15:11:05,737 INFO DataNode.clienttrace
(BlockReceiver.java:run(929)) - src: /127.0.0.1:41081, dest: /127.0.0.1:36979,
bytes: 4096, op: HDFS_WRITE, cliID: DFSClient_-1657953501, offset: 0, srvID:
DS-1024826634-67.195.138.9-36979-1239635465511, blockid:
blk_6482305749944161008_1001
[junit] 2009-04-13 15:11:05,738 INFO hdfs.StateChange
(FSNamesystem.java:addStoredBlock(3079)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:36979 is added to blk_6482305749944161008_1001 size
4096
[junit] 2009-04-13 15:11:05,738 INFO datanode.DataNode
(BlockReceiver.java:run(993)) - PacketResponder 1 for block
blk_6482305749944161008_1001 terminating
[junit] 2009-04-13 15:11:05,739 INFO hdfs.StateChange
(FSNamesystem.java:allocateBlock(1474)) - BLOCK* NameSystem.allocateBlock:
/test. blk_4263478641753483227_1001
[junit] 2009-04-13 15:11:05,740 INFO datanode.DataNode
(DataXceiver.java:writeBlock(228)) - Receiving block
blk_4263478641753483227_1001 src: /127.0.0.1:41083 dest: /127.0.0.1:36979
[junit] 2009-04-13 15:11:05,741 INFO datanode.DataNode
(DataXceiver.java:writeBlock(228)) - Receiving block
blk_4263478641753483227_1001 src: /127.0.0.1:57736 dest: /127.0.0.1:55551
[junit] 2009-04-13 15:11:05,743 INFO DataNode.clienttrace
(BlockReceiver.java:lastDataNodeRun(805)) - src: /127.0.0.1:57736, dest:
/127.0.0.1:55551, bytes: 4096, op: HDFS_WRITE, cliID: DFSClient_-1657953501,
offset: 0, srvID: DS-274840152-67.195.138.9-55551-1239635465644, blockid:
blk_4263478641753483227_1001
[junit] 2009-04-13 15:11:05,743 INFO hdfs.StateChange
(FSNamesystem.java:addStoredBlock(3079)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:55551 is added to blk_4263478641753483227_1001 size
4096
[junit] 2009-04-13 15:11:05,743 INFO datanode.DataNode
(BlockReceiver.java:lastDataNodeRun(829)) - PacketResponder 0 for block
blk_4263478641753483227_1001 terminating
[junit] 2009-04-13 15:11:05,744 INFO hdfs.StateChange
(FSNamesystem.java:addStoredBlock(3079)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:36979 is added to blk_4263478641753483227_1001 size
4096
[junit] 2009-04-13 15:11:05,744 INFO DataNode.clienttrace
(BlockReceiver.java:run(929)) - src: /127.0.0.1:41083, dest: /127.0.0.1:36979,
bytes: 4096, op: HDFS_WRITE, cliID: DFSClient_-1657953501, offset: 0, srvID:
DS-1024826634-67.195.138.9-36979-1239635465511, blockid:
blk_4263478641753483227_1001
[junit] 2009-04-13 15:11:05,745 INFO datanode.DataNode
(BlockReceiver.java:run(993)) - PacketResponder 1 for block
blk_4263478641753483227_1001 terminating
[junit] 2009-04-13 15:11:05,746 INFO namenode.FSNamesystem
(FSEditLog.java:processIOError(471)) - current list of storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 2009-04-13 15:11:05,747 INFO namenode.FSNamesystem
(FSEditLog.java:processIOError(471)) - current list of storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] init: server=localhost;port=;service=DataNode;localVMUrl=null
[junit]
[junit] Domains:
[junit] Domain = JMImplementation
[junit] Domain = com.sun.management
[junit] Domain = hadoop
[junit] Domain = java.lang
[junit] Domain = java.util.logging
[junit]
[junit] MBeanServer default domain = DefaultDomain
[junit]
[junit] MBean count = 26
[junit]
[junit] Query MBeanServer MBeans:
[junit] hadoop services:
hadoop:service=DataNode,name=DataNodeActivity-UndefinedStorageId-386755768
[junit] hadoop services:
hadoop:service=DataNode,name=DataNodeActivity-UndefinedStorageId275283970
[junit] hadoop services:
hadoop:service=DataNode,name=FSDatasetState-UndefinedStorageId-119683701
[junit] hadoop services:
hadoop:service=DataNode,name=FSDatasetState-UndefinedStorageId-1831038872
[junit] hadoop services:
hadoop:service=DataNode,name=RpcActivityForPort33805
[junit] hadoop services:
hadoop:service=DataNode,name=RpcActivityForPort53696
[junit] Info: key = bytes_written; val = 0
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 1
[junit] 2009-04-13 15:11:05,849 INFO ipc.Server (Server.java:stop(1098)) -
Stopping server on 53696
[junit] 2009-04-13 15:11:05,849 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 0 on 53696: exiting
[junit] 2009-04-13 15:11:05,850 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 2 on 53696: exiting
[junit] 2009-04-13 15:11:05,850 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 1 on 53696: exiting
[junit] 2009-04-13 15:11:05,850 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 53696
[junit] 2009-04-13 15:11:05,850 INFO ipc.Server (Server.java:run(536)) -
Stopping IPC Server Responder
[junit] 2009-04-13 15:11:05,850 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:55551,
storageID=DS-274840152-67.195.138.9-55551-1239635465644, infoPort=45660,
ipcPort=53696):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] 2009-04-13 15:11:05,850 INFO datanode.DataNode
(DataNode.java:shutdown(604)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-04-13 15:11:05,851 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(618)) - Exiting DataBlockScanner thread.
[junit] 2009-04-13 15:11:05,852 INFO datanode.DataNode
(DataNode.java:run(1234)) - DatanodeRegistration(127.0.0.1:55551,
storageID=DS-274840152-67.195.138.9-55551-1239635465644, infoPort=45660,
ipcPort=53696):Finishing DataNode in:
FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/data/data4/current'}
[junit] 2009-04-13 15:11:05,852 INFO ipc.Server (Server.java:stop(1098)) -
Stopping server on 53696
[junit] 2009-04-13 15:11:05,853 INFO datanode.DataNode
(DataNode.java:shutdown(604)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 0
[junit] 2009-04-13 15:11:05,854 INFO ipc.Server (Server.java:stop(1098)) -
Stopping server on 33805
[junit] 2009-04-13 15:11:05,854 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 0 on 33805: exiting
[junit] 2009-04-13 15:11:05,855 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 33805
[junit] 2009-04-13 15:11:05,855 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:36979,
storageID=DS-1024826634-67.195.138.9-36979-1239635465511, infoPort=40950,
ipcPort=33805):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] 2009-04-13 15:11:05,855 INFO datanode.DataNode
(DataNode.java:shutdown(604)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-04-13 15:11:05,855 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 2 on 33805: exiting
[junit] 2009-04-13 15:11:05,855 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 1 on 33805: exiting
[junit] 2009-04-13 15:11:05,857 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(618)) - Exiting DataBlockScanner thread.
[junit] 2009-04-13 15:11:05,855 INFO ipc.Server (Server.java:run(536)) -
Stopping IPC Server Responder
[junit] 2009-04-13 15:11:05,858 INFO datanode.DataNode
(DataNode.java:run(1234)) - DatanodeRegistration(127.0.0.1:36979,
storageID=DS-1024826634-67.195.138.9-36979-1239635465511, infoPort=40950,
ipcPort=33805):Finishing DataNode in:
FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/data/data1/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/data/data2/current'}
[junit] 2009-04-13 15:11:05,858 INFO ipc.Server (Server.java:stop(1098)) -
Stopping server on 33805
[junit] 2009-04-13 15:11:05,858 INFO datanode.DataNode
(DataNode.java:shutdown(604)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-04-13 15:11:05,959 WARN namenode.FSNamesystem
(FSNamesystem.java:run(2352)) - ReplicationMonitor thread received
InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 2009-04-13 15:11:05,959 INFO namenode.FSNamesystem
(FSEditLog.java:printStatistics(1082)) - Number of transactions: 3 Total time
for transactions(ms): 2Number of transactions batched in Syncs: 0 Number of
syncs: 2 SyncTimes(ms): 34 14
[junit] 2009-04-13 15:11:05,960 WARN namenode.DecommissionManager
(DecommissionManager.java:run(67)) - Monitor interrupted:
java.lang.InterruptedException: sleep interrupted
[junit] 2009-04-13 15:11:05,960 INFO namenode.FSNamesystem
(FSEditLog.java:processIOError(471)) - current list of storage
dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/test/data/dfs/name2(IMAGE_AND_EDITS);
[junit] 2009-04-13 15:11:05,961 INFO ipc.Server (Server.java:stop(1098)) -
Stopping server on 36513
[junit] 2009-04-13 15:11:05,961 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 36513
[junit] 2009-04-13 15:11:05,961 INFO ipc.Server (Server.java:run(536)) -
Stopping IPC Server Responder
[junit] 2009-04-13 15:11:05,962 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 0 on 36513: exiting
[junit] 2009-04-13 15:11:05,962 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 4 on 36513: exiting
[junit] 2009-04-13 15:11:05,962 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 5 on 36513: exiting
[junit] 2009-04-13 15:11:05,962 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 3 on 36513: exiting
[junit] 2009-04-13 15:11:05,962 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 2 on 36513: exiting
[junit] 2009-04-13 15:11:05,962 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 1 on 36513: exiting
[junit] 2009-04-13 15:11:05,963 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 9 on 36513: exiting
[junit] 2009-04-13 15:11:05,963 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 7 on 36513: exiting
[junit] 2009-04-13 15:11:05,962 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 6 on 36513: exiting
[junit] 2009-04-13 15:11:05,962 INFO ipc.Server (Server.java:run(992)) -
IPC Server handler 8 on 36513: exiting
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 4.087 sec
[junit] Running org.apache.hadoop.util.TestCyclicIteration
[junit]
[junit]
[junit] integers=[]
[junit] map={}
[junit] start=-1, iteration=[]
[junit]
[junit]
[junit] integers=[0]
[junit] map={0=0}
[junit] start=-1, iteration=[0]
[junit] start=0, iteration=[0]
[junit] start=1, iteration=[0]
[junit]
[junit]
[junit] integers=[0, 2]
[junit] map={0=0, 2=2}
[junit] start=-1, iteration=[0, 2]
[junit] start=0, iteration=[2, 0]
[junit] start=1, iteration=[2, 0]
[junit] start=2, iteration=[0, 2]
[junit] start=3, iteration=[0, 2]
[junit]
[junit]
[junit] integers=[0, 2, 4]
[junit] map={0=0, 2=2, 4=4}
[junit] start=-1, iteration=[0, 2, 4]
[junit] start=0, iteration=[2, 4, 0]
[junit] start=1, iteration=[2, 4, 0]
[junit] start=2, iteration=[4, 0, 2]
[junit] start=3, iteration=[4, 0, 2]
[junit] start=4, iteration=[0, 2, 4]
[junit] start=5, iteration=[0, 2, 4]
[junit]
[junit]
[junit] integers=[0, 2, 4, 6]
[junit] map={0=0, 2=2, 4=4, 6=6}
[junit] start=-1, iteration=[0, 2, 4, 6]
[junit] start=0, iteration=[2, 4, 6, 0]
[junit] start=1, iteration=[2, 4, 6, 0]
[junit] start=2, iteration=[4, 6, 0, 2]
[junit] start=3, iteration=[4, 6, 0, 2]
[junit] start=4, iteration=[6, 0, 2, 4]
[junit] start=5, iteration=[6, 0, 2, 4]
[junit] start=6, iteration=[0, 2, 4, 6]
[junit] start=7, iteration=[0, 2, 4, 6]
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.101 sec
[junit] Running org.apache.hadoop.util.TestGenericsUtil
[junit] 2009-04-13 15:11:06,925 WARN conf.Configuration
(Configuration.java:<clinit>(176)) - 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] 2009-04-13 15:11:06,937 WARN util.GenericOptionsParser
(GenericOptionsParser.java:parseGeneralOptions(377)) - options parsing failed:
Missing argument for option:jt
[junit] usage: general options are:
[junit] -archives <paths> comma separated archives to be
unarchived
[junit] on the compute machines.
[junit] -conf <configuration file> specify an application configuration
file
[junit] -D <property=value> use value for given property
[junit] -files <paths> comma separated files to be copied
to the
[junit] map reduce cluster
[junit] -fs <local|namenode:port> specify a namenode
[junit] -jt <local|jobtracker:port> specify a job tracker
[junit] -libjars <paths> comma separated jar files to include
in the
[junit] classpath.
[junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.185 sec
[junit] Running org.apache.hadoop.util.TestIndexedSort
[junit] sortRandom seed:
-4332669283686278723(org.apache.hadoop.util.QuickSort)
[junit] testSorted seed:
-8247351533869240910(org.apache.hadoop.util.QuickSort)
[junit] testAllEqual setting min/max at
79/358(org.apache.hadoop.util.QuickSort)
[junit] sortWritable seed:
-1699693244825218947(org.apache.hadoop.util.QuickSort)
[junit] QuickSort degen cmp/swp:
23252/3713(org.apache.hadoop.util.QuickSort)
[junit] sortRandom seed:
4803907685756422304(org.apache.hadoop.util.HeapSort)
[junit] testSorted seed:
-9008153530866001712(org.apache.hadoop.util.HeapSort)
[junit] testAllEqual setting min/max at
111/142(org.apache.hadoop.util.HeapSort)
[junit] sortWritable seed:
-6179356047062485005(org.apache.hadoop.util.HeapSort)
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 1.058 sec
[junit] Running org.apache.hadoop.util.TestProcfsBasedProcessTree
[junit] 2009-04-13 15:11:08,809 INFO util.ProcessTree
(ProcessTree.java:isSetsidSupported(54)) - setsid exited with exit code 0
[junit] 2009-04-13 15:11:09,314 INFO util.TestProcfsBasedProcessTree
(TestProcfsBasedProcessTree.java:testProcessTree(141)) - Root process pid: 24638
[junit] 2009-04-13 15:11:09,384 INFO util.TestProcfsBasedProcessTree
(TestProcfsBasedProcessTree.java:testProcessTree(146)) - ProcessTree: [ 24640
24641 24638 ]
[junit] 2009-04-13 15:11:15,932 INFO util.TestProcfsBasedProcessTree
(TestProcfsBasedProcessTree.java:testProcessTree(159)) - ProcessTree: [ 24642
24640 24646 24644 24650 24648 24638 24654 24652 ]
[junit] 2009-04-13 15:11:15,944 INFO util.TestProcfsBasedProcessTree
(TestProcfsBasedProcessTree.java:run(64)) - Shell Command exit with a non-zero
exit code. This is expected as we are killing the subprocesses of the task
intentionally. org.apache.hadoop.util.Shell$ExitCodeException:
[junit] 2009-04-13 15:11:15,944 INFO util.TestProcfsBasedProcessTree
(TestProcfsBasedProcessTree.java:run(70)) - Exit code: 143
[junit] 2009-04-13 15:11:15,946 INFO util.ProcessTree
(ProcessTree.java:destroyProcessGroup(160)) - Killing all processes in the
process group 24638 with SIGTERM. Exit code 0
[junit] 2009-04-13 15:11:16,033 INFO util.TestProcfsBasedProcessTree
(TestProcfsBasedProcessTree.java:testProcessTree(173)) - RogueTaskThread
successfully joined.
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 7.328 sec
[junit] Running org.apache.hadoop.util.TestReflectionUtils
[junit] 2009-04-13 15:11:16,974 WARN conf.Configuration
(Configuration.java:<clinit>(176)) - 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: 5, Failures: 0, Errors: 0, Time elapsed: 0.581 sec
[junit] Running org.apache.hadoop.util.TestShell
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.183 sec
[junit] Running org.apache.hadoop.util.TestStringUtils
[junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.091 sec
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :770:
Tests failed!
Total time: 184 minutes 13 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...
