See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/805/changes
Changes: [gkesavan] Increasing the java max heap [yhemanth] HADOOP-5485. Mask actions in the fair scheduler's servlet UI based on value of webinterface.private.actions. Contributed by Vinod Kumar Vavilapalli. ------------------------------------------ [...truncated 530740 lines...] [junit] 2009-04-13 10:09:46,929 INFO datanode.DataNode (DataNode.java:startDataNode(317)) - Opened info server at 40454 [junit] 2009-04-13 10:09:46,929 INFO datanode.DataNode (DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s [junit] 2009-04-13 10:09:46,930 INFO datanode.DirectoryScanner (DirectoryScanner.java:<init>(133)) - scan starts at 1239627829930 with interval 21600000 [junit] 2009-04-13 10:09:46,932 INFO http.HttpServer (HttpServer.java:start(454)) - Jetty bound to port 46694 [junit] 2009-04-13 10:09:46,932 INFO mortbay.log (?:invoke0(?)) - jetty-6.1.14 [junit] 2009-04-13 10:09:47,009 INFO mortbay.log (?:invoke0(?)) - Started selectchannelconnec...@localhost:46694 [junit] 2009-04-13 10:09:47,009 INFO jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized [junit] 2009-04-13 10:09:47,011 INFO metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, port=42407 [junit] 2009-04-13 10:09:47,011 INFO ipc.Server (Server.java:run(471)) - IPC Server Responder: starting [junit] 2009-04-13 10:09:47,012 INFO ipc.Server (Server.java:run(934)) - IPC Server handler 1 on 42407: starting [junit] 2009-04-13 10:09:47,012 INFO datanode.DataNode (DataNode.java:startDataNode(396)) - dnRegistration = DatanodeRegistration(vesta.apache.org:40454, storageID=, infoPort=46694, ipcPort=42407) [junit] 2009-04-13 10:09:47,012 INFO ipc.Server (Server.java:run(934)) - IPC Server handler 2 on 42407: starting [junit] 2009-04-13 10:09:47,011 INFO ipc.Server (Server.java:run(934)) - IPC Server handler 0 on 42407: starting [junit] 2009-04-13 10:09:47,011 INFO ipc.Server (Server.java:run(313)) - IPC Server listener on 42407: starting [junit] 2009-04-13 10:09:47,014 INFO hdfs.StateChange (FSNamesystem.java:registerDatanode(2077)) - BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:40454 storage DS-1951101531-67.195.138.9-40454-1239617387013 [junit] 2009-04-13 10:09:47,014 INFO net.NetworkTopology (NetworkTopology.java:add(328)) - Adding a new node: /default-rack/127.0.0.1:40454 [junit] 2009-04-13 10:09:47,016 INFO datanode.DataNode (DataNode.java:register(554)) - New storage id DS-1951101531-67.195.138.9-40454-1239617387013 is assigned to data-node 127.0.0.1:40454 [junit] 2009-04-13 10:09:47,017 INFO datanode.DataNode (DataNode.java:run(1214)) - DatanodeRegistration(127.0.0.1:40454, storageID=DS-1951101531-67.195.138.9-40454-1239617387013, infoPort=46694, ipcPort=42407)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 10:09:47,039 INFO datanode.DataNode (DataNode.java:offerService(696)) - using BLOCKREPORT_INTERVAL of 3600000msec Initial delay: 0msec [junit] 2009-04-13 10:09:47,048 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 10:09:47,049 INFO common.Storage (DataStorage.java:recoverTransitionRead(124)) - Formatting ... [junit] 2009-04-13 10:09:47,059 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 10:09:47,060 INFO common.Storage (DataStorage.java:recoverTransitionRead(124)) - Formatting ... [junit] 2009-04-13 10:09:47,076 INFO datanode.DataNode (DataNode.java:blockReport(925)) - BlockReport of 0 blocks got processed in 1 msecs [junit] 2009-04-13 10:09:47,077 INFO datanode.DataNode (DataNode.java:offerService(739)) - Starting Periodic block scanner. [junit] 2009-04-13 10:09:47,097 INFO datanode.DataNode (FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean [junit] 2009-04-13 10:09:47,098 INFO datanode.DataNode (DataNode.java:startDataNode(317)) - Opened info server at 52203 [junit] 2009-04-13 10:09:47,098 INFO datanode.DataNode (DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s [junit] 2009-04-13 10:09:47,098 INFO datanode.DirectoryScanner (DirectoryScanner.java:<init>(133)) - scan starts at 1239635642098 with interval 21600000 [junit] 2009-04-13 10:09:47,100 INFO http.HttpServer (HttpServer.java:start(454)) - Jetty bound to port 42364 [junit] 2009-04-13 10:09:47,100 INFO mortbay.log (?:invoke0(?)) - jetty-6.1.14 [junit] 2009-04-13 10:09:47,168 INFO mortbay.log (?:invoke0(?)) - Started selectchannelconnec...@localhost:42364 [junit] 2009-04-13 10:09:47,169 INFO jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized [junit] 2009-04-13 10:09:47,170 INFO metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, port=47466 [junit] 2009-04-13 10:09:47,171 INFO ipc.Server (Server.java:run(471)) - IPC Server Responder: starting [junit] 2009-04-13 10:09:47,171 INFO ipc.Server (Server.java:run(934)) - IPC Server handler 0 on 47466: starting [junit] 2009-04-13 10:09:47,171 INFO ipc.Server (Server.java:run(313)) - IPC Server listener on 47466: starting [junit] 2009-04-13 10:09:47,172 INFO ipc.Server (Server.java:run(934)) - IPC Server handler 1 on 47466: starting [junit] 2009-04-13 10:09:47,172 INFO datanode.DataNode (DataNode.java:startDataNode(396)) - dnRegistration = DatanodeRegistration(vesta.apache.org:52203, storageID=, infoPort=42364, ipcPort=47466) [junit] 2009-04-13 10:09:47,172 INFO ipc.Server (Server.java:run(934)) - IPC Server handler 2 on 47466: starting [junit] 2009-04-13 10:09:47,174 INFO hdfs.StateChange (FSNamesystem.java:registerDatanode(2077)) - BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:52203 storage DS-2040718447-67.195.138.9-52203-1239617387173 [junit] 2009-04-13 10:09:47,174 INFO net.NetworkTopology (NetworkTopology.java:add(328)) - Adding a new node: /default-rack/127.0.0.1:52203 [junit] 2009-04-13 10:09:47,176 INFO datanode.DataNode (DataNode.java:register(554)) - New storage id DS-2040718447-67.195.138.9-52203-1239617387173 is assigned to data-node 127.0.0.1:52203 [junit] 2009-04-13 10:09:47,177 INFO datanode.DataNode (DataNode.java:run(1214)) - DatanodeRegistration(127.0.0.1:52203, storageID=DS-2040718447-67.195.138.9-52203-1239617387173, infoPort=42364, ipcPort=47466)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 10:09:47,183 INFO datanode.DataNode (DataNode.java:offerService(696)) - using BLOCKREPORT_INTERVAL of 3600000msec Initial delay: 0msec [junit] 2009-04-13 10:09:47,213 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 10:09:47,214 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 10:09:47,222 INFO datanode.DataNode (DataNode.java:blockReport(925)) - BlockReport of 0 blocks got processed in 1 msecs [junit] 2009-04-13 10:09:47,222 INFO datanode.DataNode (DataNode.java:offerService(739)) - Starting Periodic block scanner. [junit] 2009-04-13 10:09:47,227 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 10:09:47,227 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 10:09:47,230 INFO hdfs.StateChange (FSNamesystem.java:allocateBlock(1474)) - BLOCK* NameSystem.allocateBlock: /test. blk_-7127448766874534415_1001 [junit] 2009-04-13 10:09:47,232 INFO datanode.DataNode (DataXceiver.java:writeBlock(228)) - Receiving block blk_-7127448766874534415_1001 src: /127.0.0.1:60935 dest: /127.0.0.1:52203 [junit] 2009-04-13 10:09:47,234 INFO datanode.DataNode (DataXceiver.java:writeBlock(228)) - Receiving block blk_-7127448766874534415_1001 src: /127.0.0.1:50552 dest: /127.0.0.1:40454 [junit] 2009-04-13 10:09:47,236 INFO DataNode.clienttrace (BlockReceiver.java:lastDataNodeRun(805)) - src: /127.0.0.1:50552, dest: /127.0.0.1:40454, bytes: 4096, op: HDFS_WRITE, cliID: DFSClient_1114645871, offset: 0, srvID: DS-1951101531-67.195.138.9-40454-1239617387013, blockid: blk_-7127448766874534415_1001 [junit] 2009-04-13 10:09:47,236 INFO datanode.DataNode (BlockReceiver.java:lastDataNodeRun(829)) - PacketResponder 0 for block blk_-7127448766874534415_1001 terminating [junit] 2009-04-13 10:09:47,237 INFO hdfs.StateChange (FSNamesystem.java:addStoredBlock(3079)) - BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:40454 is added to blk_-7127448766874534415_1001 size 4096 [junit] 2009-04-13 10:09:47,237 INFO DataNode.clienttrace (BlockReceiver.java:run(929)) - src: /127.0.0.1:60935, dest: /127.0.0.1:52203, bytes: 4096, op: HDFS_WRITE, cliID: DFSClient_1114645871, offset: 0, srvID: DS-2040718447-67.195.138.9-52203-1239617387173, blockid: blk_-7127448766874534415_1001 [junit] 2009-04-13 10:09:47,238 INFO datanode.DataNode (BlockReceiver.java:run(993)) - PacketResponder 1 for block blk_-7127448766874534415_1001 terminating [junit] 2009-04-13 10:09:47,238 INFO hdfs.StateChange (FSNamesystem.java:addStoredBlock(3079)) - BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:52203 is added to blk_-7127448766874534415_1001 size 4096 [junit] 2009-04-13 10:09:47,239 INFO hdfs.StateChange (FSNamesystem.java:allocateBlock(1474)) - BLOCK* NameSystem.allocateBlock: /test. blk_-2404219822504591506_1001 [junit] 2009-04-13 10:09:47,241 INFO datanode.DataNode (DataXceiver.java:writeBlock(228)) - Receiving block blk_-2404219822504591506_1001 src: /127.0.0.1:60937 dest: /127.0.0.1:52203 [junit] 2009-04-13 10:09:47,242 INFO datanode.DataNode (DataXceiver.java:writeBlock(228)) - Receiving block blk_-2404219822504591506_1001 src: /127.0.0.1:50554 dest: /127.0.0.1:40454 [junit] 2009-04-13 10:09:47,243 INFO DataNode.clienttrace (BlockReceiver.java:lastDataNodeRun(805)) - src: /127.0.0.1:50554, dest: /127.0.0.1:40454, bytes: 4096, op: HDFS_WRITE, cliID: DFSClient_1114645871, offset: 0, srvID: DS-1951101531-67.195.138.9-40454-1239617387013, blockid: blk_-2404219822504591506_1001 [junit] 2009-04-13 10:09:47,244 INFO datanode.DataNode (BlockReceiver.java:lastDataNodeRun(829)) - PacketResponder 0 for block blk_-2404219822504591506_1001 terminating [junit] 2009-04-13 10:09:47,244 INFO hdfs.StateChange (FSNamesystem.java:addStoredBlock(3079)) - BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:40454 is added to blk_-2404219822504591506_1001 size 4096 [junit] 2009-04-13 10:09:47,245 INFO DataNode.clienttrace (BlockReceiver.java:run(929)) - src: /127.0.0.1:60937, dest: /127.0.0.1:52203, bytes: 4096, op: HDFS_WRITE, cliID: DFSClient_1114645871, offset: 0, srvID: DS-2040718447-67.195.138.9-52203-1239617387173, blockid: blk_-2404219822504591506_1001 [junit] 2009-04-13 10:09:47,245 INFO hdfs.StateChange (FSNamesystem.java:addStoredBlock(3079)) - BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:52203 is added to blk_-2404219822504591506_1001 size 4096 [junit] 2009-04-13 10:09:47,245 INFO datanode.DataNode (BlockReceiver.java:run(993)) - PacketResponder 1 for block blk_-2404219822504591506_1001 terminating [junit] 2009-04-13 10:09:47,246 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 10:09:47,248 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-435320670 [junit] hadoop services: hadoop:service=DataNode,name=DataNodeActivity-UndefinedStorageId1986177400 [junit] hadoop services: hadoop:service=DataNode,name=FSDatasetState-UndefinedStorageId-1727249633 [junit] hadoop services: hadoop:service=DataNode,name=FSDatasetState-UndefinedStorageId2104421858 [junit] hadoop services: hadoop:service=DataNode,name=RpcActivityForPort42407 [junit] hadoop services: hadoop:service=DataNode,name=RpcActivityForPort47466 [junit] Info: key = bytes_written; val = 0 [junit] Shutting down the Mini HDFS Cluster [junit] Shutting down DataNode 1 [junit] 2009-04-13 10:09:47,351 INFO ipc.Server (Server.java:stop(1098)) - Stopping server on 47466 [junit] 2009-04-13 10:09:47,351 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 1 on 47466: exiting [junit] 2009-04-13 10:09:47,351 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 0 on 47466: exiting [junit] 2009-04-13 10:09:47,352 WARN datanode.DataNode (DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:52203, storageID=DS-2040718447-67.195.138.9-52203-1239617387173, infoPort=42364, ipcPort=47466):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 10:09:47,352 INFO datanode.DataNode (DataNode.java:shutdown(604)) - Waiting for threadgroup to exit, active threads is 1 [junit] 2009-04-13 10:09:47,352 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 2 on 47466: exiting [junit] 2009-04-13 10:09:47,352 INFO ipc.Server (Server.java:run(536)) - Stopping IPC Server Responder [junit] 2009-04-13 10:09:47,351 INFO ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 47466 [junit] 2009-04-13 10:09:47,352 INFO datanode.DataBlockScanner (DataBlockScanner.java:run(618)) - Exiting DataBlockScanner thread. [junit] 2009-04-13 10:09:47,353 INFO datanode.DataNode (DataNode.java:run(1234)) - DatanodeRegistration(127.0.0.1:52203, storageID=DS-2040718447-67.195.138.9-52203-1239617387173, infoPort=42364, ipcPort=47466):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 10:09:47,353 INFO ipc.Server (Server.java:stop(1098)) - Stopping server on 47466 [junit] 2009-04-13 10:09:47,354 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 10:09:47,492 INFO ipc.Server (Server.java:stop(1098)) - Stopping server on 42407 [junit] 2009-04-13 10:09:47,492 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 1 on 42407: exiting [junit] 2009-04-13 10:09:47,492 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 0 on 42407: exiting [junit] 2009-04-13 10:09:47,492 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 2 on 42407: exiting [junit] 2009-04-13 10:09:47,493 INFO ipc.Server (Server.java:run(536)) - Stopping IPC Server Responder [junit] 2009-04-13 10:09:47,492 INFO datanode.DataNode (DataNode.java:shutdown(604)) - Waiting for threadgroup to exit, active threads is 1 [junit] 2009-04-13 10:09:47,492 INFO ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 42407 [junit] 2009-04-13 10:09:47,493 WARN datanode.DataNode (DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:40454, storageID=DS-1951101531-67.195.138.9-40454-1239617387013, infoPort=46694, ipcPort=42407):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 10:09:47,494 INFO datanode.DataBlockScanner (DataBlockScanner.java:run(618)) - Exiting DataBlockScanner thread. [junit] 2009-04-13 10:09:47,494 INFO datanode.DataNode (DataNode.java:run(1234)) - DatanodeRegistration(127.0.0.1:40454, storageID=DS-1951101531-67.195.138.9-40454-1239617387013, infoPort=46694, ipcPort=42407):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 10:09:47,494 INFO ipc.Server (Server.java:stop(1098)) - Stopping server on 42407 [junit] 2009-04-13 10:09:47,494 INFO datanode.DataNode (DataNode.java:shutdown(604)) - Waiting for threadgroup to exit, active threads is 0 [junit] 2009-04-13 10:09:47,596 WARN namenode.FSNamesystem (FSNamesystem.java:run(2352)) - ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted [junit] 2009-04-13 10:09:47,596 INFO namenode.FSNamesystem (FSEditLog.java:printStatistics(1082)) - Number of transactions: 3 Total time for transactions(ms): 0Number of transactions batched in Syncs: 0 Number of syncs: 2 SyncTimes(ms): 14 1 [junit] 2009-04-13 10:09:47,596 WARN namenode.DecommissionManager (DecommissionManager.java:run(67)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted [junit] 2009-04-13 10:09:47,597 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 10:09:47,598 INFO ipc.Server (Server.java:stop(1098)) - Stopping server on 46535 [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 1 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 2 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 9 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 8 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 7 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 6 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(536)) - Stopping IPC Server Responder [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 4 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 3 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 0 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(992)) - IPC Server handler 5 on 46535: exiting [junit] 2009-04-13 10:09:47,598 INFO ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 46535 [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 3.073 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.095 sec [junit] Running org.apache.hadoop.util.TestGenericsUtil [junit] 2009-04-13 10:09:48,540 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 10:09:48,553 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.184 sec [junit] Running org.apache.hadoop.util.TestIndexedSort [junit] sortRandom seed: -1836054109297996847(org.apache.hadoop.util.QuickSort) [junit] testSorted seed: -2596117234015333285(org.apache.hadoop.util.QuickSort) [junit] testAllEqual setting min/max at 357/228(org.apache.hadoop.util.QuickSort) [junit] sortWritable seed: -716207878806992244(org.apache.hadoop.util.QuickSort) [junit] QuickSort degen cmp/swp: 23252/3713(org.apache.hadoop.util.QuickSort) [junit] sortRandom seed: -4659769549955560815(org.apache.hadoop.util.HeapSort) [junit] testSorted seed: -2482031780503863692(org.apache.hadoop.util.HeapSort) [junit] testAllEqual setting min/max at 423/493(org.apache.hadoop.util.HeapSort) [junit] sortWritable seed: -3255303311733533427(org.apache.hadoop.util.HeapSort) [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 1.002 sec [junit] Running org.apache.hadoop.util.TestProcfsBasedProcessTree [junit] 2009-04-13 10:09:50,370 INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(54)) - setsid exited with exit code 0 [junit] 2009-04-13 10:09:50,877 INFO util.TestProcfsBasedProcessTree (TestProcfsBasedProcessTree.java:testProcessTree(141)) - Root process pid: 9129 [junit] 2009-04-13 10:09:50,952 INFO util.TestProcfsBasedProcessTree (TestProcfsBasedProcessTree.java:testProcessTree(146)) - ProcessTree: [ 9132 9131 9129 ] [junit] 2009-04-13 10:09:57,535 INFO util.TestProcfsBasedProcessTree (TestProcfsBasedProcessTree.java:testProcessTree(159)) - ProcessTree: [ 9135 9133 9131 9129 9145 9143 9141 9139 9137 ] [junit] 2009-04-13 10:09:57,546 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 10:09:57,546 INFO util.TestProcfsBasedProcessTree (TestProcfsBasedProcessTree.java:run(70)) - Exit code: 143 [junit] 2009-04-13 10:09:57,547 INFO util.ProcessTree (ProcessTree.java:destroyProcessGroup(160)) - Killing all processes in the process group 9129 with SIGTERM. Exit code 0 [junit] 2009-04-13 10:09:57,597 INFO util.TestProcfsBasedProcessTree (TestProcfsBasedProcessTree.java:testProcessTree(173)) - RogueTaskThread successfully joined. [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 7.323 sec [junit] Running org.apache.hadoop.util.TestReflectionUtils [junit] 2009-04-13 10:09:58,488 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.574 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: 180 minutes 24 seconds Publishing Javadoc Recording test results Recording fingerprints Publishing Clover coverage report...