hadoop-hdfs-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Hudson Server <hud...@hudson.zones.apache.org>
Subject Build failed in Hudson: Hadoop-Hdfs-trunk #46
Date Tue, 11 Aug 2009 14:58:16 GMT
See http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/46/changes

Changes:

[szetszwo] Move HDFS-525 from 0.21.0 to 0.20.1 in CHANGES.txt.

[szetszwo] HDFS-525. The SimpleDateFormat object in ListPathsServlet is not thread safe. 
Contributed by Suresh Srinivas

------------------------------------------
[...truncated 284574 lines...]
    [junit] 2009-08-11 14:55:13,995 INFO  datanode.DataNode (DataNode.java:offerService(782))
- Starting Periodic block scanner.
    [junit] 2009-08-11 14:55:14,177 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data4
 is not formatted.
    [junit] 2009-08-11 14:55:14,177 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-08-11 14:55:14,418 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417))
- Registered FSDatasetStatusMBean
    [junit] 2009-08-11 14:55:14,418 INFO  datanode.DataNode (DataNode.java:startDataNode(326))
- Opened info server at 50135
    [junit] 2009-08-11 14:55:14,419 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74))
- Balancing bandwith is 1048576 bytes/s
    [junit] 2009-08-11 14:55:14,419 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133))
- scan starts at 1250019415419 with interval 21600000
    [junit] 2009-08-11 14:55:14,420 INFO  http.HttpServer (HttpServer.java:start(425)) - Port
returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the listener
on 0
    [junit] 2009-08-11 14:55:14,421 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort()
returned 33128 webServer.getConnectors()[0].getLocalPort() returned 33128
    [junit] 2009-08-11 14:55:14,421 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty
bound to port 33128
    [junit] 2009-08-11 14:55:14,421 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-08-11 14:55:14,484 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:33128
    [junit] 2009-08-11 14:55:14,485 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot
initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-08-11 14:55:14,486 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58))
- Initializing RPC Metrics with hostName=DataNode, port=47342
    [junit] 2009-08-11 14:55:14,487 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder:
starting
    [junit] 2009-08-11 14:55:14,487 INFO  datanode.DataNode (DataNode.java:startDataNode(404))
- dnRegistration = DatanodeRegistration(vesta.apache.org:50135, storageID=, infoPort=33128,
ipcPort=47342)
    [junit] 2009-08-11 14:55:14,487 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
0 on 47342: starting
    [junit] 2009-08-11 14:55:14,487 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener
on 47342: starting
    [junit] 2009-08-11 14:55:14,489 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1774))
- BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:50135 storage DS-1031587713-67.195.138.9-50135-1250002514488
    [junit] 2009-08-11 14:55:14,489 INFO  net.NetworkTopology (NetworkTopology.java:add(327))
- Adding a new node: /default-rack/127.0.0.1:50135
    [junit] 2009-08-11 14:55:14,530 INFO  datanode.DataNode (DataNode.java:register(571))
- New storage id DS-1031587713-67.195.138.9-50135-1250002514488 is assigned to data-node 127.0.0.1:50135
    [junit] 2009-08-11 14:55:14,531 INFO  datanode.DataNode (DataNode.java:run(1258)) - DatanodeRegistration(127.0.0.1:50135,
storageID=DS-1031587713-67.195.138.9-50135-1250002514488, infoPort=33128, ipcPort=47342)In
DataNode.run, data = FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build-fi/test/data/dfs/data/data4/current'}

    [junit] Starting DataNode 2 with dfs.data.dir: http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data5,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build-fi/test/data/dfs/data/data6

    [junit] 2009-08-11 14:55:14,531 INFO  datanode.DataNode (DataNode.java:offerService(739))
- using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-08-11 14:55:14,540 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data5
 is not formatted.
    [junit] 2009-08-11 14:55:14,541 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-08-11 14:55:14,563 INFO  datanode.DataNode (DataNode.java:blockReport(974))
- BlockReport of 0 blocks got processed in 1 msecs
    [junit] 2009-08-11 14:55:14,563 INFO  datanode.DataNode (DataNode.java:offerService(782))
- Starting Periodic block scanner.
    [junit] 2009-08-11 14:55:14,735 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data6
 is not formatted.
    [junit] 2009-08-11 14:55:14,736 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-08-11 14:55:15,042 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417))
- Registered FSDatasetStatusMBean
    [junit] 2009-08-11 14:55:15,043 INFO  datanode.DataNode (DataNode.java:startDataNode(326))
- Opened info server at 51008
    [junit] 2009-08-11 14:55:15,043 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74))
- Balancing bandwith is 1048576 bytes/s
    [junit] 2009-08-11 14:55:15,043 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133))
- scan starts at 1250020223043 with interval 21600000
    [junit] 2009-08-11 14:55:15,045 INFO  http.HttpServer (HttpServer.java:start(425)) - Port
returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the listener
on 0
    [junit] 2009-08-11 14:55:15,045 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort()
returned 49706 webServer.getConnectors()[0].getLocalPort() returned 49706
    [junit] 2009-08-11 14:55:15,045 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty
bound to port 49706
    [junit] 2009-08-11 14:55:15,045 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-08-11 14:55:15,144 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:49706
    [junit] 2009-08-11 14:55:15,145 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot
initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-08-11 14:55:15,146 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58))
- Initializing RPC Metrics with hostName=DataNode, port=42341
    [junit] 2009-08-11 14:55:15,146 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder:
starting
    [junit] 2009-08-11 14:55:15,146 INFO  datanode.DataNode (DataNode.java:startDataNode(404))
- dnRegistration = DatanodeRegistration(vesta.apache.org:51008, storageID=, infoPort=49706,
ipcPort=42341)
    [junit] 2009-08-11 14:55:15,146 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
0 on 42341: starting
    [junit] 2009-08-11 14:55:15,146 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener
on 42341: starting
    [junit] 2009-08-11 14:55:15,148 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1774))
- BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:51008 storage DS-869684786-67.195.138.9-51008-1250002515148
    [junit] 2009-08-11 14:55:15,149 INFO  net.NetworkTopology (NetworkTopology.java:add(327))
- Adding a new node: /default-rack/127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,219 INFO  datanode.DataNode (DataNode.java:register(571))
- New storage id DS-869684786-67.195.138.9-51008-1250002515148 is assigned to data-node 127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,219 INFO  datanode.DataNode (DataNode.java:run(1258)) - DatanodeRegistration(127.0.0.1:51008,
storageID=DS-869684786-67.195.138.9-51008-1250002515148, infoPort=49706, ipcPort=42341)In
DataNode.run, data = FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data5/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build-fi/test/data/dfs/data/data6/current'}

    [junit] 2009-08-11 14:55:15,220 INFO  datanode.DataNode (DataNode.java:offerService(739))
- using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-08-11 14:55:15,253 INFO  datanode.DataNode (DataNode.java:blockReport(974))
- BlockReport of 0 blocks got processed in 0 msecs
    [junit] 2009-08-11 14:55:15,254 INFO  datanode.DataNode (DataNode.java:offerService(782))
- Starting Periodic block scanner.
    [junit] 2009-08-11 14:55:15,316 INFO  FSNamesystem.audit (FSNamesystem.java:logAuditEvent(114))
- ugi=hudson,hudson	ip=/127.0.0.1	cmd=create	src=/testPipelineFi15/foo	dst=null	perm=hudson:supergroup:rw-r--r--
    [junit] 2009-08-11 14:55:15,318 INFO  hdfs.StateChange (FSNamesystem.java:allocateBlock(1303))
- BLOCK* NameSystem.allocateBlock: /testPipelineFi15/foo. blk_-9169371959972368887_1001
    [junit] 2009-08-11 14:55:15,319 INFO  protocol.ClientProtocolAspects (ClientProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_protocol_ClientProtocolAspects$1$7076326d(32))
- FI: addBlock Pipeline[127.0.0.1:50135, 127.0.0.1:51008, 127.0.0.1:35769]
    [junit] 2009-08-11 14:55:15,320 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(50))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:50135
    [junit] 2009-08-11 14:55:15,320 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(70))
- FI: receiverOpWriteBlock
    [junit] 2009-08-11 14:55:15,320 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-9169371959972368887_1001 src: /127.0.0.1:36686 dest: /127.0.0.1:50135
    [junit] 2009-08-11 14:55:15,322 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(50))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,322 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(70))
- FI: receiverOpWriteBlock
    [junit] 2009-08-11 14:55:15,322 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-9169371959972368887_1001 src: /127.0.0.1:48148 dest: /127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,324 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(50))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:35769
    [junit] 2009-08-11 14:55:15,324 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(70))
- FI: receiverOpWriteBlock
    [junit] 2009-08-11 14:55:15,324 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-9169371959972368887_1001 src: /127.0.0.1:50935 dest: /127.0.0.1:35769
    [junit] 2009-08-11 14:55:15,325 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$2$d4f6605f(60))
- FI: statusRead SUCCESS, datanode=127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,325 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$2$d4f6605f(60))
- FI: statusRead SUCCESS, datanode=127.0.0.1:50135
    [junit] 2009-08-11 14:55:15,327 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,327 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,327 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,327 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,327 INFO  fi.FiTestUtil (DataTransferTestUtil.java:run(158))
- FI: testPipelineFi15, index=1, datanode=127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,328 INFO  datanode.DataNode (BlockReceiver.java:handleMirrorOutError(185))
- DatanodeRegistration(127.0.0.1:51008, storageID=DS-869684786-67.195.138.9-51008-1250002515148,
infoPort=49706, ipcPort=42341):Exception writing block blk_-9169371959972368887_1001 to mirror
127.0.0.1:35769
    [junit] org.apache.hadoop.util.DiskChecker$DiskOutOfSpaceException: FI: testPipelineFi15,
index=1, datanode=127.0.0.1:51008
    [junit] 	at org.apache.hadoop.fi.DataTransferTestUtil$DoosAction.run(DataTransferTestUtil.java:159)
    [junit] 	at org.apache.hadoop.fi.DataTransferTestUtil$DoosAction.run(DataTransferTestUtil.java:1)
    [junit] 	at org.apache.hadoop.fi.FiTestUtil$ActionContainer.run(FiTestUtil.java:66)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiverAspects.ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(BlockReceiverAspects.aj:47)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:408)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:532)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.opWriteBlock(DataXceiver.java:339)
    [junit] 	at org.apache.hadoop.hdfs.protocol.DataTransferProtocol$Receiver.opWriteBlock(DataTransferProtocol.java:324)
    [junit] 	at org.apache.hadoop.hdfs.protocol.DataTransferProtocol$Receiver.processOp(DataTransferProtocol.java:269)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:110)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 
    [junit] 2009-08-11 14:55:15,328 INFO  datanode.DataNode (BlockReceiver.java:receiveBlock(566))
- Exception in receiveBlock for block blk_-9169371959972368887_1001 org.apache.hadoop.util.DiskChecker$DiskOutOfSpaceException:
FI: testPipelineFi15, index=1, datanode=127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,329 INFO  datanode.DataNode (BlockReceiver.java:run(907))
- PacketResponder blk_-9169371959972368887_1001 1 Exception java.io.InterruptedIOException:
Interruped while waiting for IO on channel java.nio.channels.SocketChannel[connected local=/127.0.0.1:50935
remote=/127.0.0.1:35769]. 59997 millis timeout left.
    [junit] 	at org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:349)
    [junit] 	at org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157)
    [junit] 	at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:155)
    [junit] 	at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:128)
    [junit] 	at java.io.DataInputStream.readFully(DataInputStream.java:178)
    [junit] 	at java.io.DataInputStream.readLong(DataInputStream.java:399)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver$PacketResponder.run(BlockReceiver.java:869)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 
    [junit] 2009-08-11 14:55:15,329 INFO  datanode.DataNode (BlockReceiver.java:run(922))
- PacketResponder blk_-9169371959972368887_1001 1 : Thread is interrupted.
    [junit] 2009-08-11 14:55:15,329 INFO  datanode.DataNode (BlockReceiver.java:run(1009))
- PacketResponder 1 for block blk_-9169371959972368887_1001 terminating
    [junit] 2009-08-11 14:55:15,329 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(358))
- writeBlock blk_-9169371959972368887_1001 received exception org.apache.hadoop.util.DiskChecker$DiskOutOfSpaceException:
FI: testPipelineFi15, index=1, datanode=127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,330 INFO  datanode.DataNode (BlockReceiver.java:receiveBlock(566))
- Exception in receiveBlock for block blk_-9169371959972368887_1001 java.io.EOFException:
while trying to read 65557 bytes
    [junit] 2009-08-11 14:55:15,330 INFO  datanode.DataNode (BlockReceiver.java:lastDataNodeRun(779))
- PacketResponder 0 for block blk_-9169371959972368887_1001 Interrupted.
    [junit] 2009-08-11 14:55:15,330 ERROR datanode.DataNode (DataXceiver.java:run(112)) -
DatanodeRegistration(127.0.0.1:51008, storageID=DS-869684786-67.195.138.9-51008-1250002515148,
infoPort=49706, ipcPort=42341):DataXceiver
    [junit] org.apache.hadoop.util.DiskChecker$DiskOutOfSpaceException: FI: testPipelineFi15,
index=1, datanode=127.0.0.1:51008
    [junit] 	at org.apache.hadoop.fi.DataTransferTestUtil$DoosAction.run(DataTransferTestUtil.java:159)
    [junit] 	at org.apache.hadoop.fi.DataTransferTestUtil$DoosAction.run(DataTransferTestUtil.java:1)
    [junit] 	at org.apache.hadoop.fi.FiTestUtil$ActionContainer.run(FiTestUtil.java:66)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiverAspects.ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(BlockReceiverAspects.aj:47)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:408)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:532)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.opWriteBlock(DataXceiver.java:339)
    [junit] 	at org.apache.hadoop.hdfs.protocol.DataTransferProtocol$Receiver.opWriteBlock(DataTransferProtocol.java:324)
    [junit] 	at org.apache.hadoop.hdfs.protocol.DataTransferProtocol$Receiver.processOp(DataTransferProtocol.java:269)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:110)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 2009-08-11 14:55:15,330 INFO  datanode.DataNode (BlockReceiver.java:run(907))
- PacketResponder blk_-9169371959972368887_1001 2 Exception java.io.EOFException
    [junit] 	at java.io.DataInputStream.readFully(DataInputStream.java:180)
    [junit] 	at java.io.DataInputStream.readLong(DataInputStream.java:399)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver$PacketResponder.run(BlockReceiver.java:869)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 
    [junit] 2009-08-11 14:55:15,330 INFO  datanode.DataNode (BlockReceiver.java:lastDataNodeRun(843))
- PacketResponder 0 for block blk_-9169371959972368887_1001 terminating
    [junit] 2009-08-11 14:55:15,331 INFO  datanode.DataNode (BlockReceiver.java:run(1009))
- PacketResponder 2 for block blk_-9169371959972368887_1001 terminating
    [junit] 2009-08-11 14:55:15,331 WARN  hdfs.DFSClient (DFSClient.java:run(2593)) - DFSOutputStream
ResponseProcessor exception  for block blk_-9169371959972368887_1001java.io.IOException: Bad
response ERROR for block blk_-9169371959972368887_1001 from datanode 127.0.0.1:51008
    [junit] 	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer$ResponseProcessor.run(DFSClient.java:2573)
    [junit] 
    [junit] 2009-08-11 14:55:15,331 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(358))
- writeBlock blk_-9169371959972368887_1001 received exception java.io.EOFException: while
trying to read 65557 bytes
    [junit] 2009-08-11 14:55:15,332 ERROR datanode.DataNode (DataXceiver.java:run(112)) -
DatanodeRegistration(127.0.0.1:35769, storageID=DS-78635520-67.195.138.9-35769-1250002513915,
infoPort=33783, ipcPort=43062):DataXceiver
    [junit] java.io.EOFException: while trying to read 65557 bytes
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.readToBuf(BlockReceiver.java:271)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.readNextPacket(BlockReceiver.java:315)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:379)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:532)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.opWriteBlock(DataXceiver.java:339)
    [junit] 	at org.apache.hadoop.hdfs.protocol.DataTransferProtocol$Receiver.opWriteBlock(DataTransferProtocol.java:324)
    [junit] 	at org.apache.hadoop.hdfs.protocol.DataTransferProtocol$Receiver.processOp(DataTransferProtocol.java:269)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:110)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 2009-08-11 14:55:15,333 WARN  hdfs.DFSClient (DFSClient.java:processDatanodeError(2622))
- Error Recovery for block blk_-9169371959972368887_1001 bad datanode[1] 127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,333 WARN  hdfs.DFSClient (DFSClient.java:processDatanodeError(2666))
- Error Recovery for block blk_-9169371959972368887_1001 in pipeline 127.0.0.1:50135, 127.0.0.1:51008,
127.0.0.1:35769: bad datanode 127.0.0.1:51008
    [junit] 2009-08-11 14:55:15,334 INFO  datanode.DataNode (DataNode.java:logRecoverBlock(1700))
- Client calls recoverBlock(block=blk_-9169371959972368887_1001, targets=[127.0.0.1:50135,
127.0.0.1:35769])
    [junit] 2009-08-11 14:55:15,338 INFO  datanode.DataNode (DataNode.java:updateBlock(1510))
- oldblock=blk_-9169371959972368887_1001(length=1), newblock=blk_-9169371959972368887_1002(length=0),
datanode=127.0.0.1:50135
    [junit] 2009-08-11 14:55:15,339 INFO  datanode.DataNode (DataNode.java:updateBlock(1510))
- oldblock=blk_-9169371959972368887_1001(length=0), newblock=blk_-9169371959972368887_1002(length=0),
datanode=127.0.0.1:35769
    [junit] 2009-08-11 14:55:15,339 INFO  namenode.FSNamesystem (FSNamesystem.java:commitBlockSynchronization(1613))
- commitBlockSynchronization(lastblock=blk_-9169371959972368887_1001, newgenerationstamp=1002,
newlength=0, newtargets=[127.0.0.1:50135, 127.0.0.1:35769], closeFile=false, deleteBlock=false)
    [junit] 2009-08-11 14:55:15,340 INFO  namenode.FSNamesystem (FSNamesystem.java:commitBlockSynchronization(1677))
- commitBlockSynchronization(blk_-9169371959972368887_1002) successful
    [junit] 2009-08-11 14:55:15,341 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(50))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:50135
    [junit] 2009-08-11 14:55:15,341 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(70))
- FI: receiverOpWriteBlock
    [junit] 2009-08-11 14:55:15,341 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-9169371959972368887_1002 src: /127.0.0.1:36691 dest: /127.0.0.1:50135
    [junit] 2009-08-11 14:55:15,341 INFO  datanode.DataNode (FSDataset.java:writeToBlock(1011))
- Reopen already-open Block for append blk_-9169371959972368887_1002
    [junit] 2009-08-11 14:55:15,342 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(50))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:35769
    [junit] 2009-08-11 14:55:15,342 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(70))
- FI: receiverOpWriteBlock
    [junit] 2009-08-11 14:55:15,342 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-9169371959972368887_1002 src: /127.0.0.1:50939 dest: /127.0.0.1:35769
    [junit] 2009-08-11 14:55:15,342 INFO  datanode.DataNode (FSDataset.java:writeToBlock(1011))
- Reopen already-open Block for append blk_-9169371959972368887_1002
    [junit] 2009-08-11 14:55:15,342 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$2$d4f6605f(60))
- FI: statusRead SUCCESS, datanode=127.0.0.1:50135
    [junit] 2009-08-11 14:55:15,343 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,344 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,344 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,344 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,344 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(46))
- FI: callReceivePacket
    [junit] 2009-08-11 14:55:15,346 INFO  DataNode.clienttrace (BlockReceiver.java:lastDataNodeRun(819))
- src: /127.0.0.1:50939, dest: /127.0.0.1:35769, bytes: 1, op: HDFS_WRITE, cliID: DFSClient_196313700,
offset: 0, srvID: DS-78635520-67.195.138.9-35769-1250002513915, blockid: blk_-9169371959972368887_1002,
duration: 2473681
    [junit] 2009-08-11 14:55:15,346 INFO  hdfs.StateChange (BlockManager.java:addStoredBlock(950))
- BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:35769 is added to blk_-9169371959972368887_1002
size 1
    [junit] 2009-08-11 14:55:15,346 INFO  datanode.DataNode (BlockReceiver.java:lastDataNodeRun(843))
- PacketResponder 0 for block blk_-9169371959972368887_1002 terminating
    [junit] 2009-08-11 14:55:15,383 INFO  hdfs.StateChange (BlockManager.java:addStoredBlock(950))
- BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50135 is added to blk_-9169371959972368887_1002
size 1
    [junit] 2009-08-11 14:55:15,383 INFO  DataNode.clienttrace (BlockReceiver.java:run(945))
- src: /127.0.0.1:36691, dest: /127.0.0.1:50135, bytes: 1, op: HDFS_WRITE, cliID: DFSClient_196313700,
offset: 0, srvID: DS-1031587713-67.195.138.9-50135-1250002514488, blockid: blk_-9169371959972368887_1002,
duration: 38915582
    [junit] 2009-08-11 14:55:15,384 INFO  datanode.DataNode (BlockReceiver.java:run(1009))
- PacketResponder 1 for block blk_-9169371959972368887_1002 terminating
    [junit] 2009-08-11 14:55:15,385 INFO  hdfs.StateChange (FSNamesystem.java:completeFileInternal(1269))
- DIR* NameSystem.completeFile: file /testPipelineFi15/foo is closed by DFSClient_196313700
    [junit] 2009-08-11 14:55:15,410 INFO  FSNamesystem.audit (FSNamesystem.java:logAuditEvent(114))
- ugi=hudson,hudson	ip=/127.0.0.1	cmd=open	src=/testPipelineFi15/foo	dst=null	perm=null
    [junit] 2009-08-11 14:55:15,411 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(50))
- FI: receiverOp READ_BLOCK, datanode=127.0.0.1:50135
    [junit] Shutting down the Mini HDFS Cluster
    [junit] Shutting down DataNode 2
    [junit] 2009-08-11 14:55:15,412 INFO  DataNode.clienttrace (BlockSender.java:sendBlock(417))
- src: /127.0.0.1:50135, dest: /127.0.0.1:36693, bytes: 5, op: HDFS_READ, cliID: DFSClient_196313700,
offset: 0, srvID: DS-1031587713-67.195.138.9-50135-1250002514488, blockid: blk_-9169371959972368887_1002,
duration: 229116
    [junit] 2009-08-11 14:55:15,413 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$2$d4f6605f(60))
- FI: statusRead CHECKSUM_OK, datanode=127.0.0.1:50135
    [junit] 2009-08-11 14:55:15,514 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 42341
    [junit] 2009-08-11 14:55:15,515 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 42341: exiting
    [junit] 2009-08-11 14:55:15,515 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 42341
    [junit] 2009-08-11 14:55:15,515 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-08-11 14:55:15,515 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:51008, storageID=DS-869684786-67.195.138.9-51008-1250002515148,
infoPort=49706, ipcPort=42341):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-08-11 14:55:15,516 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-08-11 14:55:15,516 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-08-11 14:55:15,517 INFO  datanode.DataNode (DataNode.java:run(1278)) - DatanodeRegistration(127.0.0.1:51008,
storageID=DS-869684786-67.195.138.9-51008-1250002515148, infoPort=49706, ipcPort=42341):Finishing
DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data5/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build-fi/test/data/dfs/data/data6/current'}

    [junit] 2009-08-11 14:55:15,517 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 42341
    [junit] 2009-08-11 14:55:15,517 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 1
    [junit] 2009-08-11 14:55:15,620 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 47342
    [junit] 2009-08-11 14:55:15,620 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 47342: exiting
    [junit] 2009-08-11 14:55:15,620 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 47342
    [junit] 2009-08-11 14:55:15,620 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-08-11 14:55:15,620 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:50135, storageID=DS-1031587713-67.195.138.9-50135-1250002514488,
infoPort=33128, ipcPort=47342):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-08-11 14:55:15,621 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-08-11 14:55:15,621 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-08-11 14:55:15,622 INFO  datanode.DataNode (DataNode.java:run(1278)) - DatanodeRegistration(127.0.0.1:50135,
storageID=DS-1031587713-67.195.138.9-50135-1250002514488, infoPort=33128, ipcPort=47342):Finishing
DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build-fi/test/data/dfs/data/data4/current'}

    [junit] 2009-08-11 14:55:15,622 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 47342
    [junit] 2009-08-11 14:55:15,622 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 0
    [junit] 2009-08-11 14:55:15,724 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 43062
    [junit] 2009-08-11 14:55:15,725 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 43062: exiting
    [junit] 2009-08-11 14:55:15,725 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 43062
    [junit] 2009-08-11 14:55:15,725 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-08-11 14:55:15,725 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:35769, storageID=DS-78635520-67.195.138.9-35769-1250002513915,
infoPort=33783, ipcPort=43062):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-08-11 14:55:15,725 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-08-11 14:55:15,726 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-08-11 14:55:15,726 INFO  datanode.DataNode (DataNode.java:run(1278)) - DatanodeRegistration(127.0.0.1:35769,
storageID=DS-78635520-67.195.138.9-35769-1250002513915, infoPort=33783, ipcPort=43062):Finishing
DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/data/dfs/data/data1/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build-fi/test/data/dfs/data/data2/current'}

    [junit] 2009-08-11 14:55:15,726 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 43062
    [junit] 2009-08-11 14:55:15,726 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-08-11 14:55:15,829 WARN  namenode.FSNamesystem (FSNamesystem.java:run(2077))
- ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException:
sleep interrupted
    [junit] 2009-08-11 14:55:15,829 INFO  namenode.FSNamesystem (FSEditLog.java:printStatistics(884))
- Number of transactions: 5 Total time for transactions(ms): 0Number of transactions batched
in Syncs: 0 Number of syncs: 2 SyncTimes(ms): 61 46 
    [junit] 2009-08-11 14:55:15,829 WARN  namenode.DecommissionManager (DecommissionManager.java:run(67))
- Monitor interrupted: java.lang.InterruptedException: sleep interrupted
    [junit] 2009-08-11 14:55:15,851 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 51185
    [junit] 2009-08-11 14:55:15,851 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
1 on 51185: exiting
    [junit] 2009-08-11 14:55:15,851 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
4 on 51185: exiting
    [junit] 2009-08-11 14:55:15,852 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
9 on 51185: exiting
    [junit] 2009-08-11 14:55:15,852 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
6 on 51185: exiting
    [junit] 2009-08-11 14:55:15,852 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
3 on 51185: exiting
    [junit] 2009-08-11 14:55:15,852 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
5 on 51185: exiting
    [junit] 2009-08-11 14:55:15,852 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
2 on 51185: exiting
    [junit] 2009-08-11 14:55:15,852 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-08-11 14:55:15,851 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 51185
    [junit] 2009-08-11 14:55:15,851 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 51185: exiting
    [junit] 2009-08-11 14:55:15,851 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
7 on 51185: exiting
    [junit] 2009-08-11 14:55:15,852 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
8 on 51185: exiting
    [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 43.55 sec

checkfailure:

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml :725: Tests
failed!

Total time: 59 minutes 38 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Mime
View raw message