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 #59
Date Sun, 23 Aug 2009 12:52:54 GMT
See http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/59/

------------------------------------------
[...truncated 226537 lines...]
    [junit] 2009-08-23 12:47:51,082 INFO  datanode.DataNode (DataNode.java:blockReport(998))
- BlockReport of 0 blocks got processed in 1 msecs
    [junit] 2009-08-23 12:47:51,083 INFO  datanode.DataNode (DataNode.java:offerService(806))
- Starting Periodic block scanner.
    [junit] 2009-08-23 12:47:51,230 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-23 12:47:51,230 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-08-23 12:47:51,539 INFO  datanode.DataNode (FSDataset.java:registerMBean(1547))
- Registered FSDatasetStatusMBean
    [junit] 2009-08-23 12:47:51,539 INFO  datanode.DataNode (DataNode.java:startDataNode(326))
- Opened info server at 48509
    [junit] 2009-08-23 12:47:51,539 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74))
- Balancing bandwith is 1048576 bytes/s
    [junit] 2009-08-23 12:47:51,540 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133))
- scan starts at 1251036241540 with interval 21600000
    [junit] 2009-08-23 12:47:51,541 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-23 12:47:51,541 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort()
returned 52070 webServer.getConnectors()[0].getLocalPort() returned 52070
    [junit] 2009-08-23 12:47:51,542 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty
bound to port 52070
    [junit] 2009-08-23 12:47:51,542 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-08-23 12:47:51,601 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:52070
    [junit] 2009-08-23 12:47:51,601 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot
initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-08-23 12:47:51,602 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58))
- Initializing RPC Metrics with hostName=DataNode, port=48832
    [junit] 2009-08-23 12:47:51,603 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder:
starting
    [junit] 2009-08-23 12:47:51,603 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
0 on 48832: starting
    [junit] 2009-08-23 12:47:51,603 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener
on 48832: starting
    [junit] 2009-08-23 12:47:51,604 INFO  datanode.DataNode (DataNode.java:startDataNode(404))
- dnRegistration = DatanodeRegistration(vesta.apache.org:48509, storageID=, infoPort=52070,
ipcPort=48832)
    [junit] 2009-08-23 12:47:51,605 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1774))
- BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:48509 storage DS-830920231-67.195.138.9-48509-1251031671604
    [junit] 2009-08-23 12:47:51,606 INFO  net.NetworkTopology (NetworkTopology.java:add(327))
- Adding a new node: /default-rack/127.0.0.1:48509
    [junit] 2009-08-23 12:47:51,650 INFO  datanode.DataNode (DataNode.java:register(571))
- New storage id DS-830920231-67.195.138.9-48509-1251031671604 is assigned to data-node 127.0.0.1:48509
    [junit] 2009-08-23 12:47:51,651 INFO  datanode.DataNode (DataNode.java:run(1285)) - DatanodeRegistration(127.0.0.1:48509,
storageID=DS-830920231-67.195.138.9-48509-1251031671604, infoPort=52070, ipcPort=48832)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-23 12:47:51,651 INFO  datanode.DataNode (DataNode.java:offerService(763))
- using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-08-23 12:47:51,688 INFO  datanode.DataNode (DataNode.java:blockReport(998))
- BlockReport of 0 blocks got processed in 2 msecs
    [junit] 2009-08-23 12:47:51,688 INFO  datanode.DataNode (DataNode.java:offerService(806))
- Starting Periodic block scanner.
    [junit] 2009-08-23 12:47:51,841 INFO  FSNamesystem.audit (FSNamesystem.java:logAuditEvent(114))
- ugi=hudson,hudson	ip=/127.0.0.1	cmd=create	src=/pipeline_Fi_16/foo	dst=null	perm=hudson:supergroup:rw-r--r--
    [junit] 2009-08-23 12:47:51,844 INFO  hdfs.StateChange (FSNamesystem.java:allocateBlock(1303))
- BLOCK* NameSystem.allocateBlock: /pipeline_Fi_16/foo. blk_-3823116340774608643_1001
    [junit] 2009-08-23 12:47:51,883 INFO  protocol.ClientProtocolAspects (ClientProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_protocol_ClientProtocolAspects$1$7076326d(35))
- FI: addBlock Pipeline[127.0.0.1:33089, 127.0.0.1:48509, 127.0.0.1:42956]
    [junit] 2009-08-23 12:47:51,884 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(51))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:33089
    [junit] 2009-08-23 12:47:51,885 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(72))
- FI: receiverOpWriteBlock
    [junit] 2009-08-23 12:47:51,885 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-3823116340774608643_1001 src: /127.0.0.1:59253 dest: /127.0.0.1:33089
    [junit] 2009-08-23 12:47:51,886 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(51))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:48509
    [junit] 2009-08-23 12:47:51,887 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(72))
- FI: receiverOpWriteBlock
    [junit] 2009-08-23 12:47:51,887 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-3823116340774608643_1001 src: /127.0.0.1:45683 dest: /127.0.0.1:48509
    [junit] 2009-08-23 12:47:51,888 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(51))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:42956
    [junit] 2009-08-23 12:47:51,888 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(72))
- FI: receiverOpWriteBlock
    [junit] 2009-08-23 12:47:51,888 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-3823116340774608643_1001 src: /127.0.0.1:48571 dest: /127.0.0.1:42956
    [junit] 2009-08-23 12:47:51,889 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$2$d4f6605f(61))
- FI: statusRead SUCCESS, datanode=127.0.0.1:48509
    [junit] 2009-08-23 12:47:51,890 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$2$d4f6605f(61))
- FI: statusRead SUCCESS, datanode=127.0.0.1:33089
    [junit] 2009-08-23 12:47:51,890 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,891 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,891 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,891 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,891 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,892 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,892 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,892 INFO  fi.FiTestUtil (DataTransferTestUtil.java:run(151))
- FI: pipeline_Fi_16, index=2, datanode=127.0.0.1:42956
    [junit] 2009-08-23 12:47:51,892 WARN  datanode.DataNode (DataNode.java:checkDiskError(702))
- checkDiskError: exception: 
    [junit] org.apache.hadoop.util.DiskChecker$DiskOutOfSpaceException: FI: pipeline_Fi_16,
index=2, datanode=127.0.0.1:42956
    [junit] 	at org.apache.hadoop.fi.DataTransferTestUtil$DoosAction.run(DataTransferTestUtil.java:152)
    [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:50)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:459)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:535)
    [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-23 12:47:51,893 INFO  mortbay.log (?:invoke(?)) - Completed FSVolumeSet.checkDirs.
Removed=0volumes. List of current volumes: 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-23 12:47:51,893 INFO  datanode.DataNode (BlockReceiver.java:receiveBlock(569))
- Exception in receiveBlock for block blk_-3823116340774608643_1001 org.apache.hadoop.util.DiskChecker$DiskOutOfSpaceException:
FI: pipeline_Fi_16, index=2, datanode=127.0.0.1:42956
    [junit] 2009-08-23 12:47:51,894 INFO  datanode.DataNode (BlockReceiver.java:lastDataNodeRun(782))
- PacketResponder 0 for block blk_-3823116340774608643_1001 Interrupted.
    [junit] 2009-08-23 12:47:51,894 INFO  datanode.DataNode (BlockReceiver.java:lastDataNodeRun(853))
- PacketResponder 0 for block blk_-3823116340774608643_1001 terminating
    [junit] 2009-08-23 12:47:51,894 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(358))
- writeBlock blk_-3823116340774608643_1001 received exception org.apache.hadoop.util.DiskChecker$DiskOutOfSpaceException:
FI: pipeline_Fi_16, index=2, datanode=127.0.0.1:42956
    [junit] 2009-08-23 12:47:51,894 ERROR datanode.DataNode (DataXceiver.java:run(112)) -
DatanodeRegistration(127.0.0.1:42956, storageID=DS-1038161714-67.195.138.9-42956-1251031670395,
infoPort=48218, ipcPort=60502):DataXceiver
    [junit] org.apache.hadoop.util.DiskChecker$DiskOutOfSpaceException: FI: pipeline_Fi_16,
index=2, datanode=127.0.0.1:42956
    [junit] 	at org.apache.hadoop.fi.DataTransferTestUtil$DoosAction.run(DataTransferTestUtil.java:152)
    [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:50)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receivePacket(BlockReceiver.java:459)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockReceiver.receiveBlock(BlockReceiver.java:535)
    [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-23 12:47:51,894 INFO  datanode.DataNode (BlockReceiver.java:run(917))
- PacketResponder blk_-3823116340774608643_1001 1 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:879)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 
    [junit] 2009-08-23 12:47:51,926 INFO  datanode.DataNode (BlockReceiver.java:run(1025))
- PacketResponder 1 for block blk_-3823116340774608643_1001 terminating
    [junit] 2009-08-23 12:47:51,926 INFO  datanode.DataNode (BlockReceiver.java:run(1025))
- PacketResponder 2 for block blk_-3823116340774608643_1001 terminating
    [junit] 2009-08-23 12:47:51,927 WARN  hdfs.DFSClient (DFSClient.java:run(2601)) - DFSOutputStream
ResponseProcessor exception  for block blk_-3823116340774608643_1001java.io.IOException: Bad
response ERROR for block blk_-3823116340774608643_1001 from datanode 127.0.0.1:42956
    [junit] 	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer$ResponseProcessor.run(DFSClient.java:2581)
    [junit] 
    [junit] 2009-08-23 12:47:51,927 WARN  hdfs.DFSClient (DFSClient.java:processDatanodeError(2630))
- Error Recovery for block blk_-3823116340774608643_1001 bad datanode[2] 127.0.0.1:42956
    [junit] 2009-08-23 12:47:51,927 WARN  hdfs.DFSClient (DFSClient.java:processDatanodeError(2674))
- Error Recovery for block blk_-3823116340774608643_1001 in pipeline 127.0.0.1:33089, 127.0.0.1:48509,
127.0.0.1:42956: bad datanode 127.0.0.1:42956
    [junit] 2009-08-23 12:47:51,930 INFO  datanode.DataNode (DataNode.java:logRecoverBlock(1727))
- Client calls recoverBlock(block=blk_-3823116340774608643_1001, targets=[127.0.0.1:33089,
127.0.0.1:48509])
    [junit] 2009-08-23 12:47:51,935 INFO  datanode.DataNode (DataNode.java:updateBlock(1537))
- oldblock=blk_-3823116340774608643_1001(length=1), newblock=blk_-3823116340774608643_1002(length=1),
datanode=127.0.0.1:33089
    [junit] 2009-08-23 12:47:51,937 INFO  datanode.DataNode (DataNode.java:updateBlock(1537))
- oldblock=blk_-3823116340774608643_1001(length=1), newblock=blk_-3823116340774608643_1002(length=1),
datanode=127.0.0.1:48509
    [junit] 2009-08-23 12:47:51,938 INFO  namenode.FSNamesystem (FSNamesystem.java:commitBlockSynchronization(1613))
- commitBlockSynchronization(lastblock=blk_-3823116340774608643_1001, newgenerationstamp=1002,
newlength=1, newtargets=[127.0.0.1:33089, 127.0.0.1:48509], closeFile=false, deleteBlock=false)
    [junit] 2009-08-23 12:47:51,939 INFO  namenode.FSNamesystem (FSNamesystem.java:commitBlockSynchronization(1677))
- commitBlockSynchronization(blk_-3823116340774608643_1002) successful
    [junit] 2009-08-23 12:47:51,941 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(51))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:33089
    [junit] 2009-08-23 12:47:51,941 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(72))
- FI: receiverOpWriteBlock
    [junit] 2009-08-23 12:47:51,941 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-3823116340774608643_1002 src: /127.0.0.1:59258 dest: /127.0.0.1:33089
    [junit] 2009-08-23 12:47:51,941 INFO  datanode.DataNode (FSDataset.java:writeToBlock(1085))
- Reopen already-open Block for append blk_-3823116340774608643_1002
    [junit] 2009-08-23 12:47:51,942 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(51))
- FI: receiverOp WRITE_BLOCK, datanode=127.0.0.1:48509
    [junit] 2009-08-23 12:47:51,942 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$3$3251489(72))
- FI: receiverOpWriteBlock
    [junit] 2009-08-23 12:47:51,942 INFO  datanode.DataNode (DataXceiver.java:opWriteBlock(222))
- Receiving block blk_-3823116340774608643_1002 src: /127.0.0.1:45688 dest: /127.0.0.1:48509
    [junit] 2009-08-23 12:47:51,943 INFO  datanode.DataNode (FSDataset.java:writeToBlock(1085))
- Reopen already-open Block for append blk_-3823116340774608643_1002
    [junit] 2009-08-23 12:47:51,943 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$2$d4f6605f(61))
- FI: statusRead SUCCESS, datanode=127.0.0.1:33089
    [junit] 2009-08-23 12:47:51,944 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,944 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,944 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,945 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,945 INFO  datanode.BlockReceiverAspects (BlockReceiverAspects.aj:ajc$before$org_apache_hadoop_hdfs_server_datanode_BlockReceiverAspects$1$4c211928(47))
- FI: callReceivePacket
    [junit] 2009-08-23 12:47:51,946 INFO  DataNode.clienttrace (BlockReceiver.java:lastDataNodeRun(822))
- src: /127.0.0.1:45688, dest: /127.0.0.1:48509, bytes: 1, op: HDFS_WRITE, cliID: DFSClient_1407762613,
offset: 0, srvID: DS-830920231-67.195.138.9-48509-1251031671604, blockid: blk_-3823116340774608643_1002,
duration: 2397143
    [junit] 2009-08-23 12:47:51,987 INFO  datanode.DataNode (BlockReceiver.java:lastDataNodeRun(853))
- PacketResponder 0 for block blk_-3823116340774608643_1002 terminating
    [junit] 2009-08-23 12:47:51,987 INFO  hdfs.StateChange (BlockManager.java:addStoredBlock(950))
- BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:48509 is added to blk_-3823116340774608643_1002
size 1
    [junit] 2009-08-23 12:47:51,989 INFO  DataNode.clienttrace (BlockReceiver.java:run(955))
- src: /127.0.0.1:59258, dest: /127.0.0.1:33089, bytes: 1, op: HDFS_WRITE, cliID: DFSClient_1407762613,
offset: 0, srvID: DS-2088916918-67.195.138.9-33089-1251031670997, blockid: blk_-3823116340774608643_1002,
duration: 45005337
    [junit] 2009-08-23 12:47:51,990 INFO  datanode.DataNode (BlockReceiver.java:run(1025))
- PacketResponder 1 for block blk_-3823116340774608643_1002 terminating
    [junit] 2009-08-23 12:47:51,990 INFO  hdfs.StateChange (BlockManager.java:addStoredBlock(950))
- BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33089 is added to blk_-3823116340774608643_1002
size 1
    [junit] 2009-08-23 12:47:51,992 INFO  hdfs.StateChange (FSNamesystem.java:completeFileInternal(1269))
- DIR* NameSystem.completeFile: file /pipeline_Fi_16/foo is closed by DFSClient_1407762613
    [junit] 2009-08-23 12:47:52,003 INFO  FSNamesystem.audit (FSNamesystem.java:logAuditEvent(114))
- ugi=hudson,hudson	ip=/127.0.0.1	cmd=open	src=/pipeline_Fi_16/foo	dst=null	perm=null
    [junit] 2009-08-23 12:47:52,005 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$1$8f59fdd7(51))
- FI: receiverOp READ_BLOCK, datanode=127.0.0.1:48509
    [junit] Shutting down the Mini HDFS Cluster
    [junit] Shutting down DataNode 2
    [junit] 2009-08-23 12:47:52,006 INFO  DataNode.clienttrace (BlockSender.java:sendBlock(417))
- src: /127.0.0.1:48509, dest: /127.0.0.1:45689, bytes: 5, op: HDFS_READ, cliID: DFSClient_1407762613,
offset: 0, srvID: DS-830920231-67.195.138.9-48509-1251031671604, blockid: blk_-3823116340774608643_1002,
duration: 250492
    [junit] 2009-08-23 12:47:52,007 INFO  datanode.DataTransferProtocolAspects (DataTransferProtocolAspects.aj:ajc$afterReturning$org_apache_hadoop_hdfs_server_datanode_DataTransferProtocolAspects$2$d4f6605f(61))
- FI: statusRead CHECKSUM_OK, datanode=127.0.0.1:48509
    [junit] 2009-08-23 12:47:52,031 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 1 time(s).
    [junit] 2009-08-23 12:47:52,108 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 48832
    [junit] 2009-08-23 12:47:52,108 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 48832: exiting
    [junit] 2009-08-23 12:47:52,108 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 48832
    [junit] 2009-08-23 12:47:52,109 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-08-23 12:47:52,109 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:48509, storageID=DS-830920231-67.195.138.9-48509-1251031671604,
infoPort=52070, ipcPort=48832):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-23 12:47:52,109 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-08-23 12:47:52,110 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-08-23 12:47:52,110 INFO  datanode.DataNode (DataNode.java:run(1305)) - DatanodeRegistration(127.0.0.1:48509,
storageID=DS-830920231-67.195.138.9-48509-1251031671604, infoPort=52070, ipcPort=48832):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-23 12:47:52,111 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 48832
    [junit] 2009-08-23 12:47:52,111 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 1
    [junit] 2009-08-23 12:47:52,231 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 58600
    [junit] 2009-08-23 12:47:52,231 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 58600: exiting
    [junit] 2009-08-23 12:47:52,233 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 58600
    [junit] 2009-08-23 12:47:52,233 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-08-23 12:47:52,233 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-08-23 12:47:52,233 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:33089, storageID=DS-2088916918-67.195.138.9-33089-1251031670997,
infoPort=49467, ipcPort=58600):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-23 12:47:52,235 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-08-23 12:47:52,236 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-08-23 12:47:52,237 INFO  datanode.DataNode (DataNode.java:run(1305)) - DatanodeRegistration(127.0.0.1:33089,
storageID=DS-2088916918-67.195.138.9-33089-1251031670997, infoPort=49467, ipcPort=58600):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-23 12:47:52,237 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 58600
    [junit] 2009-08-23 12:47:52,237 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 0
    [junit] 2009-08-23 12:47:52,340 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 60502
    [junit] 2009-08-23 12:47:52,341 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 60502
    [junit] 2009-08-23 12:47:52,342 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-08-23 12:47:52,342 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:42956, storageID=DS-1038161714-67.195.138.9-42956-1251031670395,
infoPort=48218, ipcPort=60502):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-23 12:47:52,342 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-08-23 12:47:52,341 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 60502: exiting
    [junit] 2009-08-23 12:47:52,343 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-08-23 12:47:52,343 INFO  datanode.DataNode (DataNode.java:run(1305)) - DatanodeRegistration(127.0.0.1:42956,
storageID=DS-1038161714-67.195.138.9-42956-1251031670395, infoPort=48218, ipcPort=60502):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-23 12:47:52,343 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 60502
    [junit] 2009-08-23 12:47:52,343 INFO  datanode.DataNode (DataNode.java:shutdown(643))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-08-23 12:47:52,473 WARN  namenode.DecommissionManager (DecommissionManager.java:run(67))
- Monitor interrupted: java.lang.InterruptedException: sleep interrupted
    [junit] 2009-08-23 12:47:52,473 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): 56 23 
    [junit] 2009-08-23 12:47:52,473 WARN  namenode.FSNamesystem (FSNamesystem.java:run(2077))
- ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException:
sleep interrupted
    [junit] 2009-08-23 12:47:52,495 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 46463
    [junit] 2009-08-23 12:47:52,495 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 46463: exiting
    [junit] 2009-08-23 12:47:52,495 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
1 on 46463: exiting
    [junit] 2009-08-23 12:47:52,495 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
3 on 46463: exiting
    [junit] 2009-08-23 12:47:52,496 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
9 on 46463: exiting
    [junit] 2009-08-23 12:47:52,495 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
6 on 46463: exiting
    [junit] 2009-08-23 12:47:52,495 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
2 on 46463: exiting
    [junit] 2009-08-23 12:47:52,496 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 46463
    [junit] 2009-08-23 12:47:52,496 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
8 on 46463: exiting
    [junit] 2009-08-23 12:47:52,496 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
5 on 46463: exiting
    [junit] 2009-08-23 12:47:52,496 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
7 on 46463: exiting
    [junit] 2009-08-23 12:47:52,496 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
4 on 46463: exiting
    [junit] 2009-08-23 12:47:52,497 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] Tests run: 7, Failures: 0, Errors: 1, Time elapsed: 84.843 sec
    [junit] 2009-08-23 12:47:52,544 ERROR hdfs.DFSClient (DFSClient.java:close(1084)) - Exception
closing file /pipeline_Fi_12/foo : java.io.IOException: Bad connect ack with firstBadLink
as 127.0.0.1:58044
    [junit] java.io.IOException: Bad connect ack with firstBadLink as 127.0.0.1:58044
    [junit] 	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.createBlockOutputStream(DFSClient.java:2865)
    [junit] 	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.nextBlockOutputStream(DFSClient.java:2789)
    [junit] 	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2399)
    [junit] 2009-08-23 12:47:52,545 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 2 time(s).
    [junit] 2009-08-23 12:47:53,545 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 3 time(s).
    [junit] 2009-08-23 12:47:54,545 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 4 time(s).
    [junit] 2009-08-23 12:47:55,546 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 5 time(s).
    [junit] 2009-08-23 12:47:56,546 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 6 time(s).
    [junit] 2009-08-23 12:47:57,546 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 7 time(s).
    [junit] 2009-08-23 12:47:58,547 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 8 time(s).
    [junit] 2009-08-23 12:47:59,547 INFO  ipc.Client (Client.java:handleConnectionFailure(395))
- Retrying connect to server: localhost/127.0.0.1:49694. Already tried 9 time(s).
    [junit] 2009-08-23 12:47:59,548 WARN  hdfs.DFSClient (DFSClient.java:run(1140)) - Problem
renewing lease for DFSClient_-805227971 for a period of 0 seconds. Will retry shortly...
    [junit] java.net.ConnectException: Call to localhost/127.0.0.1:49694 failed on connection
exception: java.net.ConnectException: Connection refused
    [junit] 	at org.apache.hadoop.ipc.Client.wrapException(Client.java:793)
    [junit] 	at org.apache.hadoop.ipc.Client.call(Client.java:769)
    [junit] 	at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:223)
    [junit] 	at $Proxy5.renewLease(Unknown Source)
    [junit] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    [junit] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    [junit] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    [junit] 	at java.lang.reflect.Method.invoke(Method.java:597)
    [junit] 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
    [junit] 	at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
    [junit] 	at $Proxy5.renewLease(Unknown Source)
    [junit] 	at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.renew(DFSClient.java:1115)
    [junit] 	at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.run(DFSClient.java:1131)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] Caused by: java.net.ConnectException: Connection refused
    [junit] 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
    [junit] 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
    [junit] 	at org.apache.hadoop.net.SocketIOWithTimeout.connect(SocketIOWithTimeout.java:206)
    [junit] 	at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:368)
    [junit] 	at org.apache.hadoop.ipc.Client$Connection.setupIOstreams(Client.java:325)
    [junit] 	at org.apache.hadoop.ipc.Client$Connection.access$1800(Client.java:197)
    [junit] 	at org.apache.hadoop.ipc.Client.getConnection(Client.java:886)
    [junit] 	at org.apache.hadoop.ipc.Client.call(Client.java:746)
    [junit] 	... 12 more
    [junit] Test org.apache.hadoop.hdfs.server.datanode.TestFiDataTransferProtocol FAILED

checkfailure:
    [touch] Creating http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build-fi/test/testsfailed


BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml :722: The following
error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml :363: The following
error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml :646: The following
error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml :641: The following
error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml :705: Tests
failed!

Total time: 74 minutes 6 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Mime
View raw message