See http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/1/
------------------------------------------
[...truncated 323202 lines...]
[junit] 2009-06-23 06:00:29,568 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 5 on 47957: starting
[junit] 2009-06-23 06:00:29,581 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-06-23 06:00:29,582 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-23 06:00:29,797 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-06-23 06:00:29,797 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-23 06:00:30,062 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-23 06:00:30,063 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 54453
[junit] 2009-06-23 06:00:30,063 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-23 06:00:30,063 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1245755544063 with
interval 21600000
[junit] 2009-06-23 06:00:30,065 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-23 06:00:30,065 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 39900
webServer.getConnectors()[0].getLocalPort() returned 39900
[junit] 2009-06-23 06:00:30,065 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 39900
[junit] 2009-06-23 06:00:30,065 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-23 06:00:30,124 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:39900
[junit] 2009-06-23 06:00:30,125 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-23 06:00:30,137 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=45404
[junit] 2009-06-23 06:00:30,137 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-23 06:00:30,138 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 45404: starting
[junit] 2009-06-23 06:00:30,138 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 45404: starting
[junit] 2009-06-23 06:00:30,138 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 45404: starting
[junit] 2009-06-23 06:00:30,141 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 45404: starting
[junit] 2009-06-23 06:00:30,141 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:54453, storageID=, infoPort=39900,
ipcPort=45404)
[junit] 2009-06-23 06:00:30,143 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1754)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:54453 storage
DS-718970995-67.195.138.9-54453-1245736830142
[junit] 2009-06-23 06:00:30,143 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:54453
[junit] 2009-06-23 06:00:30,190 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-718970995-67.195.138.9-54453-1245736830142 is assigned to data-node
127.0.0.1:54453
[junit] 2009-06-23 06:00:30,190 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:54453,
storageID=DS-718970995-67.195.138.9-54453-1245736830142, infoPort=39900,
ipcPort=45404)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-23 06:00:30,191 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-23 06:00:30,203 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-23 06:00:30,204 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-23 06:00:30,243 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 0
msecs
[junit] 2009-06-23 06:00:30,243 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-23 06:00:30,290 INFO mapred.JvmManager
(JvmManager.java:runChild(411)) - JVM : jvm_200906230558_0004_m_-229707029
exited. Number of tasks it ran: 1
[junit] 2009-06-23 06:00:30,411 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-23 06:00:30,412 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-23 06:00:30,720 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-23 06:00:30,722 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 33189
[junit] 2009-06-23 06:00:30,723 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-23 06:00:30,724 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1245747960724 with
interval 21600000
[junit] 2009-06-23 06:00:30,726 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-23 06:00:30,727 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 50667
webServer.getConnectors()[0].getLocalPort() returned 50667
[junit] 2009-06-23 06:00:30,728 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 50667
[junit] 2009-06-23 06:00:30,728 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-23 06:00:30,801 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:50667
[junit] 2009-06-23 06:00:30,803 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-23 06:00:30,815 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=40233
[junit] 2009-06-23 06:00:30,816 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-23 06:00:30,817 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 40233: starting
[junit] 2009-06-23 06:00:30,817 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 40233: starting
[junit] 2009-06-23 06:00:30,816 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 40233: starting
[junit] 2009-06-23 06:00:30,816 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 40233: starting
[junit] 2009-06-23 06:00:30,819 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:33189, storageID=, infoPort=50667,
ipcPort=40233)
[junit] 2009-06-23 06:00:30,821 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1754)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:33189 storage
DS-673278812-67.195.138.9-33189-1245736830820
[junit] 2009-06-23 06:00:30,821 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:33189
[junit] 2009-06-23 06:00:30,873 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-673278812-67.195.138.9-33189-1245736830820 is assigned to data-node
127.0.0.1:33189
[junit] 2009-06-23 06:00:30,874 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:33189,
storageID=DS-673278812-67.195.138.9-33189-1245736830820, infoPort=50667,
ipcPort=40233)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-23 06:00:30,875 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-23 06:00:30,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/data5
is not formatted.
[junit] 2009-06-23 06:00:30,884 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-23 06:00:30,913 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 2
msecs
[junit] 2009-06-23 06:00:30,913 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-23 06:00:31,080 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-23 06:00:31,080 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-23 06:00:31,348 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-23 06:00:31,348 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 48678
[junit] 2009-06-23 06:00:31,349 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-23 06:00:31,349 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1245749497349 with
interval 21600000
[junit] 2009-06-23 06:00:31,350 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-23 06:00:31,351 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 51591
webServer.getConnectors()[0].getLocalPort() returned 51591
[junit] 2009-06-23 06:00:31,351 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 51591
[junit] 2009-06-23 06:00:31,351 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-23 06:00:31,413 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:51591
[junit] 2009-06-23 06:00:31,416 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-23 06:00:31,428 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=55917
[junit] 2009-06-23 06:00:31,428 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-23 06:00:31,429 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 55917: starting
[junit] 2009-06-23 06:00:31,429 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:48678, storageID=, infoPort=51591,
ipcPort=55917)
[junit] 2009-06-23 06:00:31,429 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 55917: starting
[junit] 2009-06-23 06:00:31,429 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 55917: starting
[junit] 2009-06-23 06:00:31,428 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 55917: starting
[junit] 2009-06-23 06:00:31,431 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1754)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:48678 storage
DS-1005611645-67.195.138.9-48678-1245736831430
[junit] 2009-06-23 06:00:31,431 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:48678
[junit] 2009-06-23 06:00:31,480 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-1005611645-67.195.138.9-48678-1245736831430 is assigned to data-node
127.0.0.1:48678
[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-23 06:00:31,480 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:48678,
storageID=DS-1005611645-67.195.138.9-48678-1245736831430, infoPort=51591,
ipcPort=55917)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] 2009-06-23 06:00:31,481 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-23 06:00:31,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/data7
is not formatted.
[junit] 2009-06-23 06:00:31,491 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-23 06:00:31,524 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-06-23 06:00:31,524 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-23 06:00:31,686 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-23 06:00:31,686 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-23 06:00:31,948 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-23 06:00:31,948 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 35838
[junit] 2009-06-23 06:00:31,948 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-23 06:00:31,949 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1245740440949 with
interval 21600000
[junit] 2009-06-23 06:00:31,950 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-23 06:00:31,950 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 33278
webServer.getConnectors()[0].getLocalPort() returned 33278
[junit] 2009-06-23 06:00:31,951 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 33278
[junit] 2009-06-23 06:00:31,951 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-23 06:00:32,009 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:33278
[junit] 2009-06-23 06:00:32,010 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-23 06:00:32,021 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=50094
[junit] 2009-06-23 06:00:32,022 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-23 06:00:32,023 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 50094: starting
[junit] 2009-06-23 06:00:32,022 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 50094: starting
[junit] 2009-06-23 06:00:32,022 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 50094: starting
[junit] 2009-06-23 06:00:32,023 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:35838, storageID=, infoPort=33278,
ipcPort=50094)
[junit] 2009-06-23 06:00:32,023 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 50094: starting
[junit] 2009-06-23 06:00:32,025 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1754)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:35838 storage
DS-1461206063-67.195.138.9-35838-1245736832024
[junit] 2009-06-23 06:00:32,025 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:35838
[junit] 2009-06-23 06:00:32,068 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-1461206063-67.195.138.9-35838-1245736832024 is assigned to data-node
127.0.0.1:35838
[junit] 2009-06-23 06:00:32,068 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:35838,
storageID=DS-1461206063-67.195.138.9-35838-1245736832024, infoPort=33278,
ipcPort=50094)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-23 06:00:32,076 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-23 06:00:32,123 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-06-23 06:00:32,124 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-23 06:00:32,166 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-23 06:00:32,269 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 50094
[junit] 2009-06-23 06:00:32,270 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 50094: exiting
[junit] 2009-06-23 06:00:32,270 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 50094: exiting
[junit] 2009-06-23 06:00:32,270 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 50094: exiting
[junit] 2009-06-23 06:00:32,271 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:35838,
storageID=DS-1461206063-67.195.138.9-35838-1245736832024, infoPort=33278,
ipcPort=50094):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-23 06:00:32,271 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-23 06:00:32,271 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-23 06:00:32,271 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 50094
[junit] 2009-06-23 06:00:32,273 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-23 06:00:32,274 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:35838,
storageID=DS-1461206063-67.195.138.9-35838-1245736832024, infoPort=33278,
ipcPort=50094):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-23 06:00:32,274 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 50094
[junit] 2009-06-23 06:00:32,274 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 2
[junit] 2009-06-23 06:00:32,376 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 55917
[junit] 2009-06-23 06:00:32,377 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 55917: exiting
[junit] 2009-06-23 06:00:32,377 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 55917
[junit] 2009-06-23 06:00:32,377 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-23 06:00:32,378 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 55917: exiting
[junit] 2009-06-23 06:00:32,378 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 55917: exiting
[junit] 2009-06-23 06:00:32,377 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:48678,
storageID=DS-1005611645-67.195.138.9-48678-1245736831430, infoPort=51591,
ipcPort=55917):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-23 06:00:32,377 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-23 06:00:32,379 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-23 06:00:32,379 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:48678,
storageID=DS-1005611645-67.195.138.9-48678-1245736831430, infoPort=51591,
ipcPort=55917):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-23 06:00:32,379 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 55917
[junit] 2009-06-23 06:00:32,380 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 1
[junit] 2009-06-23 06:00:32,481 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 40233
[junit] 2009-06-23 06:00:32,482 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 40233: exiting
[junit] 2009-06-23 06:00:32,482 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 40233
[junit] 2009-06-23 06:00:32,482 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-23 06:00:32,483 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 40233: exiting
[junit] 2009-06-23 06:00:32,482 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:33189,
storageID=DS-673278812-67.195.138.9-33189-1245736830820, infoPort=50667,
ipcPort=40233):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-23 06:00:32,482 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-23 06:00:32,482 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 40233: exiting
[junit] 2009-06-23 06:00:32,483 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-23 06:00:32,484 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:33189,
storageID=DS-673278812-67.195.138.9-33189-1245736830820, infoPort=50667,
ipcPort=40233):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-23 06:00:32,484 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 40233
[junit] 2009-06-23 06:00:32,485 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 0
[junit] 2009-06-23 06:00:32,587 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 45404
[junit] 2009-06-23 06:00:32,587 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 45404: exiting
[junit] 2009-06-23 06:00:32,587 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-23 06:00:32,587 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:54453,
storageID=DS-718970995-67.195.138.9-54453-1245736830142, infoPort=39900,
ipcPort=45404):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-23 06:00:32,587 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-23 06:00:32,587 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 45404
[junit] 2009-06-23 06:00:32,588 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-23 06:00:32,587 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 45404: exiting
[junit] 2009-06-23 06:00:32,588 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 45404: exiting
[junit] 2009-06-23 06:00:32,589 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:54453,
storageID=DS-718970995-67.195.138.9-54453-1245736830142, infoPort=39900,
ipcPort=45404):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-23 06:00:32,589 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 45404
[junit] 2009-06-23 06:00:32,589 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-06-23 06:00:32,691 WARN namenode.DecommissionManager
(DecommissionManager.java:run(67)) - Monitor interrupted:
java.lang.InterruptedException: sleep interrupted
[junit] 2009-06-23 06:00:32,691 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-23 06:00:32,691 WARN namenode.FSNamesystem
(FSNamesystem.java:run(2057)) - ReplicationMonitor thread received
InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 2009-06-23 06:00:32,794 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 47957
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 47957: exiting
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 47957: exiting
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 47957
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 3 on 47957: exiting
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 9 on 47957: exiting
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 5 on 47957: exiting
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 6 on 47957: exiting
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 4 on 47957: exiting
[junit] 2009-06-23 06:00:32,795 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 8 on 47957: exiting
[junit] 2009-06-23 06:00:32,797 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 47957: exiting
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 125.198 sec
[junit] 2009-06-23 06:00:32,796 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 7 on 47957: exiting
checkfailure:
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml
:538: Tests failed!
Total time: 76 minutes 32 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...
