You are viewing a plain text version of this content. The canonical link for it is here.
Posted to hdfs-dev@hadoop.apache.org by Apache Hudson Server <hu...@hudson.zones.apache.org> on 2009/07/16 15:35:43 UTC

Build failed in Hudson: Hadoop-Hdfs-trunk #24

See http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/24/

------------------------------------------
[...truncated 297895 lines...]
    [junit] 2009-07-16 13:33:34,303 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/data1  is not formatted.
    [junit] 2009-07-16 13:33:34,304 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-07-16 13:33:34,521 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/data2  is not formatted.
    [junit] 2009-07-16 13:33:34,521 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-07-16 13:33:34,795 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
    [junit] 2009-07-16 13:33:34,795 INFO  datanode.DataNode (DataNode.java:startDataNode(326)) - Opened info server at 56496
    [junit] 2009-07-16 13:33:34,795 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2009-07-16 13:33:34,796 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133)) - scan starts at 1247767161796 with interval 21600000
    [junit] 2009-07-16 13:33:34,797 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-07-16 13:33:34,797 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 37925 webServer.getConnectors()[0].getLocalPort() returned 37925
    [junit] 2009-07-16 13:33:34,798 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 37925
    [junit] 2009-07-16 13:33:34,798 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-07-16 13:33:34,937 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:37925
    [junit] 2009-07-16 13:33:34,938 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-07-16 13:33:34,965 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, port=46086
    [junit] 2009-07-16 13:33:34,966 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-07-16 13:33:34,966 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 46086: starting
    [junit] 2009-07-16 13:33:34,966 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 46086: starting
    [junit] 2009-07-16 13:33:34,966 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 46086: starting
    [junit] 2009-07-16 13:33:34,969 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 46086: starting
    [junit] 2009-07-16 13:33:34,969 INFO  datanode.DataNode (DataNode.java:startDataNode(404)) - dnRegistration = DatanodeRegistration(vesta.apache.org:56496, storageID=, infoPort=37925, ipcPort=46086)
    [junit] 2009-07-16 13:33:34,971 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1772)) - BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:56496 storage DS-1494695667-67.195.138.9-56496-1247751214970
    [junit] 2009-07-16 13:33:34,971 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/127.0.0.1:56496
    [junit] 2009-07-16 13:33:35,036 INFO  datanode.DataNode (DataNode.java:register(566)) - New storage id DS-1494695667-67.195.138.9-56496-1247751214970 is assigned to data-node 127.0.0.1:56496
    [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-07-16 13:33:35,037 INFO  datanode.DataNode (DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:56496, storageID=DS-1494695667-67.195.138.9-56496-1247751214970, infoPort=37925, ipcPort=46086)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] 2009-07-16 13:33:35,037 INFO  datanode.DataNode (DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-07-16 13:33:35,049 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-07-16 13:33:35,050 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-07-16 13:33:35,086 INFO  datanode.DataNode (DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1 msecs
    [junit] 2009-07-16 13:33:35,087 INFO  datanode.DataNode (DataNode.java:offerService(777)) - Starting Periodic block scanner.
    [junit] 2009-07-16 13:33:35,236 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-07-16 13:33:35,236 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-07-16 13:33:35,512 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
    [junit] 2009-07-16 13:33:35,512 INFO  datanode.DataNode (DataNode.java:startDataNode(326)) - Opened info server at 36224
    [junit] 2009-07-16 13:33:35,512 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2009-07-16 13:33:35,513 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133)) - scan starts at 1247772402513 with interval 21600000
    [junit] 2009-07-16 13:33:35,514 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-07-16 13:33:35,514 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 58782 webServer.getConnectors()[0].getLocalPort() returned 58782
    [junit] 2009-07-16 13:33:35,515 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 58782
    [junit] 2009-07-16 13:33:35,515 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-07-16 13:33:35,579 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:58782
    [junit] 2009-07-16 13:33:35,580 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-07-16 13:33:35,593 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, port=56430
    [junit] 2009-07-16 13:33:35,593 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-07-16 13:33:35,594 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 56430: starting
    [junit] 2009-07-16 13:33:35,593 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 56430: starting
    [junit] 2009-07-16 13:33:35,597 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 56430: starting
    [junit] 2009-07-16 13:33:35,597 INFO  datanode.DataNode (DataNode.java:startDataNode(404)) - dnRegistration = DatanodeRegistration(vesta.apache.org:36224, storageID=, infoPort=58782, ipcPort=56430)
    [junit] 2009-07-16 13:33:35,597 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 56430: starting
    [junit] 2009-07-16 13:33:35,598 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1772)) - BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:36224 storage DS-805176506-67.195.138.9-36224-1247751215597
    [junit] 2009-07-16 13:33:35,598 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/127.0.0.1:36224
    [junit] 2009-07-16 13:33:35,670 INFO  datanode.DataNode (DataNode.java:register(566)) - New storage id DS-805176506-67.195.138.9-36224-1247751215597 is assigned to data-node 127.0.0.1:36224
    [junit] 2009-07-16 13:33:35,670 INFO  datanode.DataNode (DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:36224, storageID=DS-805176506-67.195.138.9-36224-1247751215597, infoPort=58782, ipcPort=56430)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-07-16 13:33:35,671 INFO  datanode.DataNode (DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-07-16 13:33:35,683 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-07-16 13:33:35,684 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-07-16 13:33:35,724 INFO  datanode.DataNode (DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1 msecs
    [junit] 2009-07-16 13:33:35,724 INFO  datanode.DataNode (DataNode.java:offerService(777)) - Starting Periodic block scanner.
    [junit] 2009-07-16 13:33:35,795 INFO  mapred.JvmManager (JvmManager.java:runChild(411)) - JVM : jvm_200907161331_0004_m_573203212 exited. Number of tasks it ran: 1
    [junit] 2009-07-16 13:33:35,879 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-07-16 13:33:35,879 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-07-16 13:33:36,157 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
    [junit] 2009-07-16 13:33:36,158 INFO  datanode.DataNode (DataNode.java:startDataNode(326)) - Opened info server at 54462
    [junit] 2009-07-16 13:33:36,158 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2009-07-16 13:33:36,158 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133)) - scan starts at 1247766475158 with interval 21600000
    [junit] 2009-07-16 13:33:36,160 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-07-16 13:33:36,160 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 58286 webServer.getConnectors()[0].getLocalPort() returned 58286
    [junit] 2009-07-16 13:33:36,160 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 58286
    [junit] 2009-07-16 13:33:36,161 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-07-16 13:33:36,226 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:58286
    [junit] 2009-07-16 13:33:36,227 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-07-16 13:33:36,239 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, port=33563
    [junit] 2009-07-16 13:33:36,239 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-07-16 13:33:36,240 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 33563: starting
    [junit] 2009-07-16 13:33:36,239 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 33563: starting
    [junit] 2009-07-16 13:33:36,239 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 33563: starting
    [junit] 2009-07-16 13:33:36,240 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 33563: starting
    [junit] 2009-07-16 13:33:36,240 INFO  datanode.DataNode (DataNode.java:startDataNode(404)) - dnRegistration = DatanodeRegistration(vesta.apache.org:54462, storageID=, infoPort=58286, ipcPort=33563)
    [junit] 2009-07-16 13:33:36,242 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1772)) - BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:54462 storage DS-947682361-67.195.138.9-54462-1247751216241
    [junit] 2009-07-16 13:33:36,242 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/127.0.0.1:54462
    [junit] 2009-07-16 13:33:36,289 INFO  datanode.DataNode (DataNode.java:register(566)) - New storage id DS-947682361-67.195.138.9-54462-1247751216241 is assigned to data-node 127.0.0.1:54462
    [junit] 2009-07-16 13:33:36,290 INFO  datanode.DataNode (DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:54462, storageID=DS-947682361-67.195.138.9-54462-1247751216241, infoPort=58286, ipcPort=33563)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-07-16 13:33:36,291 INFO  datanode.DataNode (DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-07-16 13:33:36,302 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-07-16 13:33:36,303 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-07-16 13:33:36,340 INFO  datanode.DataNode (DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 0 msecs
    [junit] 2009-07-16 13:33:36,341 INFO  datanode.DataNode (DataNode.java:offerService(777)) - Starting Periodic block scanner.
    [junit] 2009-07-16 13:33:36,490 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-07-16 13:33:36,490 INFO  common.Storage (DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-07-16 13:33:36,777 INFO  datanode.DataNode (FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
    [junit] 2009-07-16 13:33:36,778 INFO  datanode.DataNode (DataNode.java:startDataNode(326)) - Opened info server at 39508
    [junit] 2009-07-16 13:33:36,778 INFO  datanode.DataNode (DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2009-07-16 13:33:36,778 INFO  datanode.DirectoryScanner (DirectoryScanner.java:<init>(133)) - scan starts at 1247752484778 with interval 21600000
    [junit] 2009-07-16 13:33:36,780 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-07-16 13:33:36,780 INFO  http.HttpServer (HttpServer.java:start(430)) - listener.getLocalPort() returned 55480 webServer.getConnectors()[0].getLocalPort() returned 55480
    [junit] 2009-07-16 13:33:36,780 INFO  http.HttpServer (HttpServer.java:start(463)) - Jetty bound to port 55480
    [junit] 2009-07-16 13:33:36,781 INFO  mortbay.log (?:invoke(?)) - jetty-6.1.14
    [junit] 2009-07-16 13:33:36,845 INFO  mortbay.log (?:invoke(?)) - Started SelectChannelConnector@localhost:55480
    [junit] 2009-07-16 13:33:36,846 INFO  jvm.JvmMetrics (JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with processName=DataNode, sessionId=null - already initialized
    [junit] 2009-07-16 13:33:36,857 INFO  metrics.RpcMetrics (RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, port=52083
    [junit] 2009-07-16 13:33:36,858 INFO  ipc.Server (Server.java:run(474)) - IPC Server Responder: starting
    [junit] 2009-07-16 13:33:36,858 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 1 on 52083: starting
    [junit] 2009-07-16 13:33:36,859 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 2 on 52083: starting
    [junit] 2009-07-16 13:33:36,858 INFO  ipc.Server (Server.java:run(939)) - IPC Server handler 0 on 52083: starting
    [junit] 2009-07-16 13:33:36,859 INFO  datanode.DataNode (DataNode.java:startDataNode(404)) - dnRegistration = DatanodeRegistration(vesta.apache.org:39508, storageID=, infoPort=55480, ipcPort=52083)
    [junit] 2009-07-16 13:33:36,858 INFO  ipc.Server (Server.java:run(313)) - IPC Server listener on 52083: starting
    [junit] 2009-07-16 13:33:36,861 INFO  hdfs.StateChange (FSNamesystem.java:registerDatanode(1772)) - BLOCK* NameSystem.registerDatanode: node registration from 127.0.0.1:39508 storage DS-40614974-67.195.138.9-39508-1247751216860
    [junit] 2009-07-16 13:33:36,861 INFO  net.NetworkTopology (NetworkTopology.java:add(327)) - Adding a new node: /default-rack/127.0.0.1:39508
    [junit] 2009-07-16 13:33:36,897 INFO  datanode.DataNode (DataNode.java:register(566)) - New storage id DS-40614974-67.195.138.9-39508-1247751216860 is assigned to data-node 127.0.0.1:39508
    [junit] 2009-07-16 13:33:36,897 INFO  datanode.DataNode (DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:39508, storageID=DS-40614974-67.195.138.9-39508-1247751216860, infoPort=55480, ipcPort=52083)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-07-16 13:33:36,908 INFO  datanode.DataNode (DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec Initial delay: 0msec
    [junit] 2009-07-16 13:33:37,046 INFO  datanode.DataNode (DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1 msecs
    [junit] 2009-07-16 13:33:37,046 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-07-16 13:33:37,082 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-07-16 13:33:37,186 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 52083
    [junit] 2009-07-16 13:33:37,186 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 52083: exiting
    [junit] 2009-07-16 13:33:37,186 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 52083: exiting
    [junit] 2009-07-16 13:33:37,187 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 52083
    [junit] 2009-07-16 13:33:37,187 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-07-16 13:33:37,187 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 52083: exiting
    [junit] 2009-07-16 13:33:37,187 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-07-16 13:33:37,187 WARN  datanode.DataNode (DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:39508, storageID=DS-40614974-67.195.138.9-39508-1247751216860, infoPort=55480, ipcPort=52083):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-07-16 13:33:37,189 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-07-16 13:33:37,190 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-07-16 13:33:37,190 INFO  datanode.DataNode (DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:39508, storageID=DS-40614974-67.195.138.9-39508-1247751216860, infoPort=55480, ipcPort=52083):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-07-16 13:33:37,191 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 52083
    [junit] 2009-07-16 13:33:37,191 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 2
    [junit] 2009-07-16 13:33:37,293 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 33563
    [junit] 2009-07-16 13:33:37,294 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 33563: exiting
    [junit] 2009-07-16 13:33:37,294 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 33563: exiting
    [junit] 2009-07-16 13:33:37,294 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 33563
    [junit] 2009-07-16 13:33:37,295 WARN  datanode.DataNode (DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:54462, storageID=DS-947682361-67.195.138.9-54462-1247751216241, infoPort=58286, ipcPort=33563):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-07-16 13:33:37,295 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-07-16 13:33:37,295 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-07-16 13:33:37,295 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-07-16 13:33:37,295 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 33563: exiting
    [junit] 2009-07-16 13:33:37,296 INFO  datanode.DataNode (DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:54462, storageID=DS-947682361-67.195.138.9-54462-1247751216241, infoPort=58286, ipcPort=33563):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-07-16 13:33:37,296 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 33563
    [junit] 2009-07-16 13:33:37,296 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 1
    [junit] 2009-07-16 13:33:37,398 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 56430
    [junit] 2009-07-16 13:33:37,398 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 56430: exiting
    [junit] 2009-07-16 13:33:37,399 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 56430: exiting
    [junit] 2009-07-16 13:33:37,399 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 56430: exiting
    [junit] 2009-07-16 13:33:37,399 WARN  datanode.DataNode (DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:36224, storageID=DS-805176506-67.195.138.9-36224-1247751215597, infoPort=58782, ipcPort=56430):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-07-16 13:33:37,399 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 56430
    [junit] 2009-07-16 13:33:37,399 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 1
    [junit] 2009-07-16 13:33:37,399 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-07-16 13:33:37,400 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-07-16 13:33:37,400 INFO  datanode.DataNode (DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:36224, storageID=DS-805176506-67.195.138.9-36224-1247751215597, infoPort=58782, ipcPort=56430):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-07-16 13:33:37,401 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 56430
    [junit] 2009-07-16 13:33:37,401 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 0
    [junit] Shutting down DataNode 0
    [junit] 2009-07-16 13:33:37,503 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 46086
    [junit] 2009-07-16 13:33:37,503 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 46086: exiting
    [junit] 2009-07-16 13:33:37,503 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 46086: exiting
    [junit] 2009-07-16 13:33:37,504 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 46086
    [junit] 2009-07-16 13:33:37,504 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 46086: exiting
    [junit] 2009-07-16 13:33:37,504 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] 2009-07-16 13:33:37,504 WARN  datanode.DataNode (DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:56496, storageID=DS-1494695667-67.195.138.9-56496-1247751214970, infoPort=37925, ipcPort=46086):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-07-16 13:33:37,505 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-07-16 13:33:37,505 INFO  datanode.DataBlockScanner (DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-07-16 13:33:37,505 INFO  datanode.DataNode (DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:56496, storageID=DS-1494695667-67.195.138.9-56496-1247751214970, infoPort=37925, ipcPort=46086):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-07-16 13:33:37,505 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 46086
    [junit] 2009-07-16 13:33:37,506 INFO  datanode.DataNode (DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads is 0
    [junit] 2009-07-16 13:33:37,608 WARN  namenode.FSNamesystem (FSNamesystem.java:run(2075)) - ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
    [junit] 2009-07-16 13:33:37,608 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-07-16 13:33:37,608 WARN  namenode.DecommissionManager (DecommissionManager.java:run(67)) - Monitor interrupted: java.lang.InterruptedException: sleep interrupted
    [junit] 2009-07-16 13:33:37,705 INFO  ipc.Server (Server.java:stop(1103)) - Stopping server on 55234
    [junit] 2009-07-16 13:33:37,706 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 1 on 55234: exiting
    [junit] 2009-07-16 13:33:37,706 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 3 on 55234: exiting
    [junit] 2009-07-16 13:33:37,706 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 2 on 55234: exiting
    [junit] 2009-07-16 13:33:37,706 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 0 on 55234: exiting
    [junit] 2009-07-16 13:33:37,706 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 4 on 55234: exiting
    [junit] 2009-07-16 13:33:37,707 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 6 on 55234: exiting
    [junit] 2009-07-16 13:33:37,707 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 5 on 55234: exiting
    [junit] 2009-07-16 13:33:37,707 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 7 on 55234: exiting
    [junit] 2009-07-16 13:33:37,707 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 8 on 55234: exiting
    [junit] 2009-07-16 13:33:37,707 INFO  ipc.Server (Server.java:run(997)) - IPC Server handler 9 on 55234: exiting
    [junit] 2009-07-16 13:33:37,708 INFO  ipc.Server (Server.java:run(352)) - Stopping IPC Server listener on 55234
    [junit] 2009-07-16 13:33:37,708 INFO  ipc.Server (Server.java:run(539)) - Stopping IPC Server Responder
    [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 150.914 sec

checkfailure:

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

Total time: 92 minutes 26 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...


Hudson build is back to normal: Hadoop-Hdfs-trunk #25

Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/25/changes