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 #3
Date Thu, 25 Jun 2009 12:45:37 GMT
See http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/3/

------------------------------------------
[...truncated 286679 lines...]
    [junit] 2009-06-25 12:42:02,252 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-06-25 12:42:02,534 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417))
- Registered FSDatasetStatusMBean
    [junit] 2009-06-25 12:42:02,535 INFO  datanode.DataNode (DataNode.java:startDataNode(326))
- Opened info server at 56993
    [junit] 2009-06-25 12:42:02,535 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74))
- Balancing bandwith is 1048576 bytes/s
    [junit] 2009-06-25 12:42:02,535 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133))
- scan starts at 1245953187535 with interval 21600000
    [junit] 2009-06-25 12:42:02,537 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-06-25 12:42:02,537 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort()
returned 37123 webServer.getConnectors()[0].getLocalPort() returned 37123
    [junit] 2009-06-25 12:42:02,538 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty
bound to port 37123
    [junit] 2009-06-25 12:42:02,538 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-06-25 12:42:02,604 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:37123
    [junit] 2009-06-25 12:42:02,605 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot
initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-06-25 12:42:02,617 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58))
- Initializing RPC Metrics with hostName=DataNode, port=49739
    [junit] 2009-06-25 12:42:02,617 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder:
starting
    [junit] 2009-06-25 12:42:02,618 INFO  datanode.DataNode (DataNode.java:startDataNode(404))
- dnRegistration = DatanodeRegistration(vesta.apache.org:56993, storageID=, infoPort=37123,
ipcPort=49739)
    [junit] 2009-06-25 12:42:02,618 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
1 on 49739: starting
    [junit] 2009-06-25 12:42:02,618 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
0 on 49739: starting
    [junit] 2009-06-25 12:42:02,617 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener
on 49739: starting
    [junit] 2009-06-25 12:42:02,618 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
2 on 49739: starting
    [junit] 2009-06-25 12:42:02,620 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1769))
- BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:56993 storage DS-639695067-67.195.138.9-56993-1245933722618
    [junit] 2009-06-25 12:42:02,620 INFO  net.NetworkTopology (NetworkTopology.java:add(327))
- Adding a new node: /default-rack/127.0.0.1:56993
    [junit] 2009-06-25 12:42:02,667 INFO  datanode.DataNode (DataNode.java:register(566))
- New storage id DS-639695067-67.195.138.9-56993-1245933722618 is assigned to data-node 127.0.0.1:56993
    [junit] 2009-06-25 12:42:02,668 INFO  datanode.DataNode (DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:56993,
storageID=DS-639695067-67.195.138.9-56993-1245933722618, infoPort=37123, ipcPort=49739)In
DataNode.run, data = FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data1/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-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-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data3,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/data/data4

    [junit] 2009-06-25 12:42:02,668 INFO  datanode.DataNode (DataNode.java:offerService(734))
- using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-06-25 12:42:02,678 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data3
 is not formatted.
    [junit] 2009-06-25 12:42:02,679 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-06-25 12:42:02,715 INFO  datanode.DataNode (DataNode.java:blockReport(969))
- BlockReport of 0 blocks got processed in 1 msecs
    [junit] 2009-06-25 12:42:02,715 INFO  datanode.DataNode (DataNode.java:offerService(777))
- Starting Periodic block scanner.
    [junit] 2009-06-25 12:42:02,746 INFO  mapred.JvmManager (JvmManager.java:runChild(411))
- JVM : jvm_200906251240_0004_m_-1309382494 exited. Number of tasks it ran: 1
    [junit] 2009-06-25 12:42:02,884 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data4
 is not formatted.
    [junit] 2009-06-25 12:42:02,884 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-06-25 12:42:03,161 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417))
- Registered FSDatasetStatusMBean
    [junit] 2009-06-25 12:42:03,161 INFO  datanode.DataNode (DataNode.java:startDataNode(326))
- Opened info server at 47252
    [junit] 2009-06-25 12:42:03,161 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74))
- Balancing bandwith is 1048576 bytes/s
    [junit] 2009-06-25 12:42:03,162 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133))
- scan starts at 1245952108162 with interval 21600000
    [junit] 2009-06-25 12:42:03,163 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-06-25 12:42:03,163 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort()
returned 40982 webServer.getConnectors()[0].getLocalPort() returned 40982
    [junit] 2009-06-25 12:42:03,164 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty
bound to port 40982
    [junit] 2009-06-25 12:42:03,164 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-06-25 12:42:03,226 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:40982
    [junit] 2009-06-25 12:42:03,226 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot
initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-06-25 12:42:03,238 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58))
- Initializing RPC Metrics with hostName=DataNode, port=58490
    [junit] 2009-06-25 12:42:03,239 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder:
starting
    [junit] 2009-06-25 12:42:03,239 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
1 on 58490: starting
    [junit] 2009-06-25 12:42:03,239 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
0 on 58490: starting
    [junit] 2009-06-25 12:42:03,239 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener
on 58490: starting
    [junit] 2009-06-25 12:42:03,240 INFO  datanode.DataNode (DataNode.java:startDataNode(404))
- dnRegistration = DatanodeRegistration(vesta.apache.org:47252, storageID=, infoPort=40982,
ipcPort=58490)
    [junit] 2009-06-25 12:42:03,240 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
2 on 58490: starting
    [junit] 2009-06-25 12:42:03,242 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1769))
- BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:47252 storage DS-320199961-67.195.138.9-47252-1245933723241
    [junit] 2009-06-25 12:42:03,242 INFO  net.NetworkTopology (NetworkTopology.java:add(327))
- Adding a new node: /default-rack/127.0.0.1:47252
    [junit] 2009-06-25 12:42:03,317 INFO  datanode.DataNode (DataNode.java:register(566))
- New storage id DS-320199961-67.195.138.9-47252-1245933723241 is assigned to data-node 127.0.0.1:47252
    [junit] 2009-06-25 12:42:03,317 INFO  datanode.DataNode (DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:47252,
storageID=DS-320199961-67.195.138.9-47252-1245933723241, infoPort=40982, ipcPort=58490)In
DataNode.run, data = FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/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/test/data/dfs/data/data5,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/data/data6

    [junit] 2009-06-25 12:42:03,318 INFO  datanode.DataNode (DataNode.java:offerService(734))
- using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-06-25 12:42:03,327 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data5
 is not formatted.
    [junit] 2009-06-25 12:42:03,327 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-06-25 12:42:03,354 INFO  datanode.DataNode (DataNode.java:blockReport(969))
- BlockReport of 0 blocks got processed in 0 msecs
    [junit] 2009-06-25 12:42:03,354 INFO  datanode.DataNode (DataNode.java:offerService(777))
- Starting Periodic block scanner.
    [junit] 2009-06-25 12:42:03,516 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data6
 is not formatted.
    [junit] 2009-06-25 12:42:03,517 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-06-25 12:42:03,778 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417))
- Registered FSDatasetStatusMBean
    [junit] 2009-06-25 12:42:03,778 INFO  datanode.DataNode (DataNode.java:startDataNode(326))
- Opened info server at 32836
    [junit] 2009-06-25 12:42:03,779 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74))
- Balancing bandwith is 1048576 bytes/s
    [junit] 2009-06-25 12:42:03,779 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133))
- scan starts at 1245935681779 with interval 21600000
    [junit] 2009-06-25 12:42:03,781 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-06-25 12:42:03,782 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort()
returned 40224 webServer.getConnectors()[0].getLocalPort() returned 40224
    [junit] 2009-06-25 12:42:03,782 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty
bound to port 40224
    [junit] 2009-06-25 12:42:03,782 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-06-25 12:42:03,850 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:40224
    [junit] 2009-06-25 12:42:03,853 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot
initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-06-25 12:42:03,865 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58))
- Initializing RPC Metrics with hostName=DataNode, port=38119
    [junit] 2009-06-25 12:42:03,866 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder:
starting
    [junit] 2009-06-25 12:42:03,866 INFO  datanode.DataNode (DataNode.java:startDataNode(404))
- dnRegistration = DatanodeRegistration(vesta.apache.org:32836, storageID=, infoPort=40224,
ipcPort=38119)
    [junit] 2009-06-25 12:42:03,866 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
1 on 38119: starting
    [junit] 2009-06-25 12:42:03,866 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
0 on 38119: starting
    [junit] 2009-06-25 12:42:03,866 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener
on 38119: starting
    [junit] 2009-06-25 12:42:03,867 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
2 on 38119: starting
    [junit] 2009-06-25 12:42:03,869 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1769))
- BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:32836 storage DS-530170639-67.195.138.9-32836-1245933723867
    [junit] 2009-06-25 12:42:03,869 INFO  net.NetworkTopology (NetworkTopology.java:add(327))
- Adding a new node: /default-rack/127.0.0.1:32836
    [junit] 2009-06-25 12:42:03,936 INFO  datanode.DataNode (DataNode.java:register(566))
- New storage id DS-530170639-67.195.138.9-32836-1245933723867 is assigned to data-node 127.0.0.1:32836
    [junit] 2009-06-25 12:42:03,937 INFO  datanode.DataNode (DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:32836,
storageID=DS-530170639-67.195.138.9-32836-1245933723867, infoPort=40224, ipcPort=38119)In
DataNode.run, data = FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data5/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/data/data6/current'}

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

    [junit] 2009-06-25 12:42:03,937 INFO  datanode.DataNode (DataNode.java:offerService(734))
- using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-06-25 12:42:03,947 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data7
 is not formatted.
    [junit] 2009-06-25 12:42:03,948 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-06-25 12:42:03,982 INFO  datanode.DataNode (DataNode.java:blockReport(969))
- BlockReport of 0 blocks got processed in 0 msecs
    [junit] 2009-06-25 12:42:03,983 INFO  datanode.DataNode (DataNode.java:offerService(777))
- Starting Periodic block scanner.
    [junit] 2009-06-25 12:42:04,145 INFO  common.Storage (DataStorage.java:recoverTransitionRead(122))
- Storage directory http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data8
 is not formatted.
    [junit] 2009-06-25 12:42:04,146 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123))
- Formatting ...
    [junit] 2009-06-25 12:42:04,392 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417))
- Registered FSDatasetStatusMBean
    [junit] 2009-06-25 12:42:04,393 INFO  datanode.DataNode (DataNode.java:startDataNode(326))
- Opened info server at 48287
    [junit] 2009-06-25 12:42:04,393 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74))
- Balancing bandwith is 1048576 bytes/s
    [junit] 2009-06-25 12:42:04,393 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133))
- scan starts at 1245950459393 with interval 21600000
    [junit] 2009-06-25 12:42:04,395 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-06-25 12:42:04,395 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort()
returned 44888 webServer.getConnectors()[0].getLocalPort() returned 44888
    [junit] 2009-06-25 12:42:04,396 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty
bound to port 44888
    [junit] 2009-06-25 12:42:04,396 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-06-25 12:42:04,542 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:44888
    [junit] 2009-06-25 12:42:04,543 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot
initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-06-25 12:42:04,554 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58))
- Initializing RPC Metrics with hostName=DataNode, port=59143
    [junit] 2009-06-25 12:42:04,555 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder:
starting
    [junit] 2009-06-25 12:42:04,555 INFO  datanode.DataNode (DataNode.java:startDataNode(404))
- dnRegistration = DatanodeRegistration(vesta.apache.org:48287, storageID=, infoPort=44888,
ipcPort=59143)
    [junit] 2009-06-25 12:42:04,555 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
2 on 59143: starting
    [junit] 2009-06-25 12:42:04,555 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
1 on 59143: starting
    [junit] 2009-06-25 12:42:04,555 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler
0 on 59143: starting
    [junit] 2009-06-25 12:42:04,555 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener
on 59143: starting
    [junit] 2009-06-25 12:42:04,558 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1769))
- BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:48287 storage DS-1148706719-67.195.138.9-48287-1245933724556
    [junit] 2009-06-25 12:42:04,558 INFO  net.NetworkTopology (NetworkTopology.java:add(327))
- Adding a new node: /default-rack/127.0.0.1:48287
    [junit] 2009-06-25 12:42:04,602 INFO  datanode.DataNode (DataNode.java:register(566))
- New storage id DS-1148706719-67.195.138.9-48287-1245933724556 is assigned to data-node 127.0.0.1:48287
    [junit] 2009-06-25 12:42:04,603 INFO  datanode.DataNode (DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:48287,
storageID=DS-1148706719-67.195.138.9-48287-1245933724556, infoPort=44888, ipcPort=59143)In
DataNode.run, data = FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data7/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/data/data8/current'}

    [junit] 2009-06-25 12:42:04,609 INFO  datanode.DataNode (DataNode.java:offerService(734))
- using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-06-25 12:42:04,662 INFO  datanode.DataNode (DataNode.java:blockReport(969))
- BlockReport of 0 blocks got processed in 1 msecs
    [junit] 2009-06-25 12:42:04,663 INFO  datanode.DataNode (DataNode.java:offerService(777))
- Starting Periodic block scanner.
    [junit] <property><name>security.client.protocol.acl</name><value>*</value></property>
    [junit] 
    [junit] <property><name>security.client.datanode.protocol.acl</name><value>*</value></property>
    [junit] 
    [junit] <property><name>security.datanode.protocol.acl</name><value>*</value></property>
    [junit] 
    [junit] <property><name>security.inter.datanode.protocol.acl</name><value>*</value></property>
    [junit] 
    [junit] <property><name>security.namenode.protocol.acl</name><value>*</value></property>
    [junit] 
    [junit] <property><name>security.refresh.policy.protocol.acl</name><value>nouser
nogroup</value></property>
    [junit] 
    [junit] 2009-06-25 12:42:04,699 INFO  authorize.ServiceAuthorizationManager (ServiceAuthorizationManager.java:run(92))
- Authorization failed for dev,null
    [junit] java.security.AccessControlException: access denied ConnectionPermission(org.apache.hadoop.security.authorize.RefreshAuthorizationPolicyProtocol)
    [junit] 	at java.security.AccessControlContext.checkPermission(AccessControlContext.java:323)
    [junit] 	at java.security.AccessController.checkPermission(AccessController.java:546)
    [junit] 	at org.apache.hadoop.security.authorize.ServiceAuthorizationManager$1.run(ServiceAuthorizationManager.java:89)
    [junit] 	at org.apache.hadoop.security.authorize.ServiceAuthorizationManager$1.run(ServiceAuthorizationManager.java:84)
    [junit] 	at java.security.AccessController.doPrivileged(Native Method)
    [junit] 	at javax.security.auth.Subject.doAs(Subject.java:396)
    [junit] 	at org.apache.hadoop.security.authorize.ServiceAuthorizationManager.checkPermission(ServiceAuthorizationManager.java:83)
    [junit] 	at org.apache.hadoop.security.authorize.ServiceAuthorizationManager.authorize(ServiceAuthorizationManager.java:68)
    [junit] 	at org.apache.hadoop.ipc.RPC$Server.authorize(RPC.java:565)
    [junit] 	at org.apache.hadoop.ipc.Server$Connection.readAndProcess(Server.java:858)
    [junit] 	at org.apache.hadoop.ipc.Server$Listener.doRead(Server.java:420)
    [junit] 	at org.apache.hadoop.ipc.Server$Listener.run(Server.java:328)
    [junit] Good, refresh worked... refresh failed with: 
    [junit] Shutting down the Mini HDFS Cluster
    [junit] Shutting down DataNode 3
    [junit] 2009-06-25 12:42:04,812 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 59143
    [junit] 2009-06-25 12:42:04,813 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
1 on 59143: exiting
    [junit] 2009-06-25 12:42:04,813 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 59143: exiting
    [junit] 2009-06-25 12:42:04,817 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-06-25 12:42:04,815 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
2 on 59143: exiting
    [junit] 2009-06-25 12:42:04,813 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-06-25 12:42:04,813 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 59143
    [junit] 2009-06-25 12:42:04,817 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:48287, storageID=DS-1148706719-67.195.138.9-48287-1245933724556,
infoPort=44888, ipcPort=59143):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-06-25 12:42:04,820 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-06-25 12:42:04,821 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-06-25 12:42:04,824 INFO  datanode.DataNode (DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:48287,
storageID=DS-1148706719-67.195.138.9-48287-1245933724556, infoPort=44888, ipcPort=59143):Finishing
DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data7/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/data/data8/current'}

    [junit] 2009-06-25 12:42:04,824 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 59143
    [junit] 2009-06-25 12:42:04,824 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 2
    [junit] 2009-06-25 12:42:04,930 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 38119
    [junit] 2009-06-25 12:42:04,930 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
2 on 38119: exiting
    [junit] 2009-06-25 12:42:04,930 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-06-25 12:42:04,930 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 38119
    [junit] 2009-06-25 12:42:04,931 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
1 on 38119: exiting
    [junit] 2009-06-25 12:42:04,930 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-06-25 12:42:04,931 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:32836, storageID=DS-530170639-67.195.138.9-32836-1245933723867,
infoPort=40224, ipcPort=38119):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-06-25 12:42:04,930 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 38119: exiting
    [junit] 2009-06-25 12:42:04,933 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-06-25 12:42:04,933 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-06-25 12:42:04,934 INFO  datanode.DataNode (DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:32836,
storageID=DS-530170639-67.195.138.9-32836-1245933723867, infoPort=40224, ipcPort=38119):Finishing
DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data5/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/data/data6/current'}

    [junit] 2009-06-25 12:42:04,934 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 38119
    [junit] 2009-06-25 12:42:04,934 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 1
    [junit] 2009-06-25 12:42:05,072 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 58490
    [junit] 2009-06-25 12:42:05,072 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
1 on 58490: exiting
    [junit] 2009-06-25 12:42:05,073 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 58490: exiting
    [junit] 2009-06-25 12:42:05,073 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
2 on 58490: exiting
    [junit] 2009-06-25 12:42:05,073 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-06-25 12:42:05,073 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 58490
    [junit] 2009-06-25 12:42:05,073 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:47252, storageID=DS-320199961-67.195.138.9-47252-1245933723241,
infoPort=40982, ipcPort=58490):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-06-25 12:42:05,073 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-06-25 12:42:05,076 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-06-25 12:42:05,076 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-06-25 12:42:05,076 INFO  datanode.DataNode (DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:47252,
storageID=DS-320199961-67.195.138.9-47252-1245933723241, infoPort=40982, ipcPort=58490):Finishing
DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/data/data4/current'}

    [junit] 2009-06-25 12:42:05,076 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 58490
    [junit] 2009-06-25 12:42:05,077 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 0
    [junit] 2009-06-25 12:42:05,178 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 49739
    [junit] 2009-06-25 12:42:05,179 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 49739
    [junit] 2009-06-25 12:42:05,179 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
2 on 49739: exiting
    [junit] 2009-06-25 12:42:05,179 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
1 on 49739: exiting
    [junit] 2009-06-25 12:42:05,179 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-06-25 12:42:05,179 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] 2009-06-25 12:42:05,179 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 49739: exiting
    [junit] 2009-06-25 12:42:05,179 WARN  datanode.DataNode (DataXceiverServer.java:run(137))
- DatanodeRegistration(127.0.0.1:56993, storageID=DS-639695067-67.195.138.9-56993-1245933722618,
infoPort=37123, ipcPort=49739):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-06-25 12:42:05,182 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-06-25 12:42:05,182 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616))
- Exiting DataBlockScanner thread.
    [junit] 2009-06-25 12:42:05,182 INFO  datanode.DataNode (DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:56993,
storageID=DS-639695067-67.195.138.9-56993-1245933722618, infoPort=37123, ipcPort=49739):Finishing
DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build/test/data/dfs/data/data1/current,/home/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/data/data2/current'}

    [junit] 2009-06-25 12:42:05,182 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 49739
    [junit] 2009-06-25 12:42:05,183 INFO  datanode.DataNode (DataNode.java:shutdown(638))
- Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-06-25 12:42:05,285 WARN  namenode.FSNamesystem (FSNamesystem.java:run(2072))
- ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException:
sleep interrupted
    [junit] 2009-06-25 12:42:05,285 INFO  namenode.FSNamesystem (FSEditLog.java:printStatistics(876))
- Number of transactions: 0 Total time for transactions(ms): 0Number of transactions batched
in Syncs: 0 Number of syncs: 0 SyncTimes(ms): 0 0 
    [junit] 2009-06-25 12:42:05,285 WARN  namenode.DecommissionManager (DecommissionManager.java:run(67))
- Monitor interrupted: java.lang.InterruptedException: sleep interrupted
    [junit] 2009-06-25 12:42:05,356 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server
on 44052
    [junit] 2009-06-25 12:42:05,356 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
0 on 44052: exiting
    [junit] 2009-06-25 12:42:05,356 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
3 on 44052: exiting
    [junit] 2009-06-25 12:42:05,356 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
2 on 44052: exiting
    [junit] 2009-06-25 12:42:05,356 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
1 on 44052: exiting
    [junit] 2009-06-25 12:42:05,357 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
7 on 44052: exiting
    [junit] 2009-06-25 12:42:05,357 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
5 on 44052: exiting
    [junit] 2009-06-25 12:42:05,357 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
9 on 44052: exiting
    [junit] 2009-06-25 12:42:05,357 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
6 on 44052: exiting
    [junit] 2009-06-25 12:42:05,357 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
4 on 44052: exiting
    [junit] 2009-06-25 12:42:05,357 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler
8 on 44052: exiting
    [junit] 2009-06-25 12:42:05,359 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC
Server listener on 44052
    [junit] 2009-06-25 12:42:05,359 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC
Server Responder
    [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 125.317 sec

checkfailure:

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

Total time: 68 minutes 11 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Mime
View raw message