See http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/6/
------------------------------------------
[...truncated 272199 lines...]
[junit] 2009-06-28 12:46:39,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/data2
is not formatted.
[junit] 2009-06-28 12:46:39,490 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-28 12:46:39,748 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-28 12:46:39,748 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 41455
[junit] 2009-06-28 12:46:39,749 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-28 12:46:39,749 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1246212254749 with
interval 21600000
[junit] 2009-06-28 12:46:39,751 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-28 12:46:39,751 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 35161
webServer.getConnectors()[0].getLocalPort() returned 35161
[junit] 2009-06-28 12:46:39,751 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 35161
[junit] 2009-06-28 12:46:39,752 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-28 12:46:39,817 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:35161
[junit] 2009-06-28 12:46:39,817 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-28 12:46:39,829 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=50674
[junit] 2009-06-28 12:46:39,829 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-28 12:46:39,830 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:41455, storageID=, infoPort=35161,
ipcPort=50674)
[junit] 2009-06-28 12:46:39,830 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 50674: starting
[junit] 2009-06-28 12:46:39,830 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 50674: starting
[junit] 2009-06-28 12:46:39,830 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 50674: starting
[junit] 2009-06-28 12:46:39,829 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 50674: starting
[junit] 2009-06-28 12:46:39,832 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1772)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:41455 storage
DS-1226412148-67.195.138.9-41455-1246193199831
[junit] 2009-06-28 12:46:39,833 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:41455
[junit] 2009-06-28 12:46:39,875 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-1226412148-67.195.138.9-41455-1246193199831 is assigned to data-node
127.0.0.1:41455
[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-28 12:46:39,876 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:41455,
storageID=DS-1226412148-67.195.138.9-41455-1246193199831, infoPort=35161,
ipcPort=50674)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-06-28 12:46:39,876 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-28 12:46:39,886 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-28 12:46:39,887 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-28 12:46:39,921 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-06-28 12:46:39,922 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-28 12:46:40,063 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-28 12:46:40,063 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-28 12:46:40,203 INFO mapred.JvmManager
(JvmManager.java:runChild(411)) - JVM : jvm_200906281244_0004_m_453253270
exited. Number of tasks it ran: 1
[junit] 2009-06-28 12:46:40,349 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-28 12:46:40,349 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 36308
[junit] 2009-06-28 12:46:40,349 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-28 12:46:40,350 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1246203856350 with
interval 21600000
[junit] 2009-06-28 12:46:40,351 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-28 12:46:40,351 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 43614
webServer.getConnectors()[0].getLocalPort() returned 43614
[junit] 2009-06-28 12:46:40,352 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 43614
[junit] 2009-06-28 12:46:40,352 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-28 12:46:40,414 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:43614
[junit] 2009-06-28 12:46:40,415 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-28 12:46:40,426 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=59615
[junit] 2009-06-28 12:46:40,427 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-28 12:46:40,427 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 59615: starting
[junit] 2009-06-28 12:46:40,427 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 59615: starting
[junit] 2009-06-28 12:46:40,427 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 59615: starting
[junit] 2009-06-28 12:46:40,427 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 59615: starting
[junit] 2009-06-28 12:46:40,428 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:36308, storageID=, infoPort=43614,
ipcPort=59615)
[junit] 2009-06-28 12:46:40,430 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1772)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:36308 storage
DS-2026207998-67.195.138.9-36308-1246193200429
[junit] 2009-06-28 12:46:40,430 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:36308
[junit] 2009-06-28 12:46:40,502 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-2026207998-67.195.138.9-36308-1246193200429 is assigned to data-node
127.0.0.1:36308
[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-28 12:46:40,502 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:36308,
storageID=DS-2026207998-67.195.138.9-36308-1246193200429, infoPort=43614,
ipcPort=59615)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] 2009-06-28 12:46:40,503 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-28 12:46:40,514 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-28 12:46:40,515 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-28 12:46:40,543 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 0
msecs
[junit] 2009-06-28 12:46:40,544 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-28 12:46:40,697 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-28 12:46:40,697 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-28 12:46:40,951 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-28 12:46:40,952 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 49211
[junit] 2009-06-28 12:46:40,952 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-28 12:46:40,953 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1246203848953 with
interval 21600000
[junit] 2009-06-28 12:46:40,954 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-28 12:46:40,955 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 56356
webServer.getConnectors()[0].getLocalPort() returned 56356
[junit] 2009-06-28 12:46:40,955 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 56356
[junit] 2009-06-28 12:46:40,955 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-28 12:46:41,038 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:56356
[junit] 2009-06-28 12:46:41,040 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-28 12:46:41,052 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=50558
[junit] 2009-06-28 12:46:41,053 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-28 12:46:41,053 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 50558: starting
[junit] 2009-06-28 12:46:41,053 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 50558: starting
[junit] 2009-06-28 12:46:41,053 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 50558: starting
[junit] 2009-06-28 12:46:41,058 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 50558: starting
[junit] 2009-06-28 12:46:41,058 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:49211, storageID=, infoPort=56356,
ipcPort=50558)
[junit] 2009-06-28 12:46:41,059 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1772)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:49211 storage
DS-1277956712-67.195.138.9-49211-1246193201059
[junit] 2009-06-28 12:46:41,060 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:49211
[junit] 2009-06-28 12:46:41,098 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-1277956712-67.195.138.9-49211-1246193201059 is assigned to data-node
127.0.0.1:49211
[junit] 2009-06-28 12:46:41,098 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:49211,
storageID=DS-1277956712-67.195.138.9-49211-1246193201059, infoPort=56356,
ipcPort=50558)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-28 12:46:41,099 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-28 12:46:41,108 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-28 12:46:41,109 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-28 12:46:41,142 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-06-28 12:46:41,143 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-28 12:46:41,277 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-28 12:46:41,277 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-28 12:46:41,513 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-28 12:46:41,513 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 39791
[junit] 2009-06-28 12:46:41,513 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-28 12:46:41,514 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1246197541514 with
interval 21600000
[junit] 2009-06-28 12:46:41,515 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-28 12:46:41,515 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 43840
webServer.getConnectors()[0].getLocalPort() returned 43840
[junit] 2009-06-28 12:46:41,516 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 43840
[junit] 2009-06-28 12:46:41,516 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-28 12:46:41,582 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:43840
[junit] 2009-06-28 12:46:41,582 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-28 12:46:41,594 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=38585
[junit] 2009-06-28 12:46:41,595 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-28 12:46:41,595 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 38585: starting
[junit] 2009-06-28 12:46:41,595 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 38585: starting
[junit] 2009-06-28 12:46:41,595 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 38585: starting
[junit] 2009-06-28 12:46:41,595 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 38585: starting
[junit] 2009-06-28 12:46:41,597 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:39791, storageID=, infoPort=43840,
ipcPort=38585)
[junit] 2009-06-28 12:46:41,601 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1772)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:39791 storage
DS-2036690959-67.195.138.9-39791-1246193201600
[junit] 2009-06-28 12:46:41,601 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:39791
[junit] 2009-06-28 12:46:41,642 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-2036690959-67.195.138.9-39791-1246193201600 is assigned to data-node
127.0.0.1:39791
[junit] 2009-06-28 12:46:41,642 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:39791,
storageID=DS-2036690959-67.195.138.9-39791-1246193201600, infoPort=43840,
ipcPort=38585)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-28 12:46:41,651 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-28 12:46:41,701 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 0
msecs
[junit] 2009-06-28 12:46:41,702 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-28 12:46:41,746 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-28 12:46:41,893 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 38585
[junit] 2009-06-28 12:46:41,894 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 38585: exiting
[junit] 2009-06-28 12:46:41,894 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 38585: exiting
[junit] 2009-06-28 12:46:41,894 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 38585
[junit] 2009-06-28 12:46:41,894 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-28 12:46:41,895 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-28 12:46:41,895 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 38585: exiting
[junit] 2009-06-28 12:46:41,895 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:39791,
storageID=DS-2036690959-67.195.138.9-39791-1246193201600, infoPort=43840,
ipcPort=38585):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-28 12:46:41,898 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-06-28 12:46:41,898 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-28 12:46:41,898 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:39791,
storageID=DS-2036690959-67.195.138.9-39791-1246193201600, infoPort=43840,
ipcPort=38585):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-28 12:46:41,899 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 38585
[junit] 2009-06-28 12:46:41,899 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 2
[junit] 2009-06-28 12:46:42,001 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 50558
[junit] 2009-06-28 12:46:42,002 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 50558: exiting
[junit] 2009-06-28 12:46:42,002 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 50558: exiting
[junit] 2009-06-28 12:46:42,002 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 50558: exiting
[junit] 2009-06-28 12:46:42,003 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 50558
[junit] 2009-06-28 12:46:42,003 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-28 12:46:42,003 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-28 12:46:42,003 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:49211,
storageID=DS-1277956712-67.195.138.9-49211-1246193201059, infoPort=56356,
ipcPort=50558):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-28 12:46:42,006 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-06-28 12:46:42,006 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-28 12:46:42,006 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:49211,
storageID=DS-1277956712-67.195.138.9-49211-1246193201059, infoPort=56356,
ipcPort=50558):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-28 12:46:42,007 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 50558
[junit] 2009-06-28 12:46:42,007 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 1
[junit] 2009-06-28 12:46:42,109 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 59615
[junit] 2009-06-28 12:46:42,110 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 59615: exiting
[junit] 2009-06-28 12:46:42,110 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-28 12:46:42,110 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 59615: exiting
[junit] 2009-06-28 12:46:42,110 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:36308,
storageID=DS-2026207998-67.195.138.9-36308-1246193200429, infoPort=43614,
ipcPort=59615):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-28 12:46:42,110 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 59615
[junit] 2009-06-28 12:46:42,110 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-28 12:46:42,110 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 59615: exiting
[junit] 2009-06-28 12:46:42,113 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-06-28 12:46:42,113 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-28 12:46:42,113 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:36308,
storageID=DS-2026207998-67.195.138.9-36308-1246193200429, infoPort=43614,
ipcPort=59615):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-28 12:46:42,113 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 59615
[junit] 2009-06-28 12:46:42,114 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 0
[junit] 2009-06-28 12:46:42,217 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 50674
[junit] 2009-06-28 12:46:42,217 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 50674: exiting
[junit] 2009-06-28 12:46:42,217 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 50674
[junit] 2009-06-28 12:46:42,218 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 50674: exiting
[junit] 2009-06-28 12:46:42,218 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 50674: exiting
[junit] 2009-06-28 12:46:42,217 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:41455,
storageID=DS-1226412148-67.195.138.9-41455-1246193199831, infoPort=35161,
ipcPort=50674):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-28 12:46:42,217 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-28 12:46:42,217 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-28 12:46:42,219 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-28 12:46:42,220 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:41455,
storageID=DS-1226412148-67.195.138.9-41455-1246193199831, infoPort=35161,
ipcPort=50674):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-28 12:46:42,220 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 50674
[junit] 2009-06-28 12:46:42,220 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-06-28 12:46:42,322 WARN namenode.DecommissionManager
(DecommissionManager.java:run(67)) - Monitor interrupted:
java.lang.InterruptedException: sleep interrupted
[junit] 2009-06-28 12:46:42,322 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-28 12:46:42,323 WARN namenode.FSNamesystem
(FSNamesystem.java:run(2075)) - ReplicationMonitor thread received
InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 2009-06-28 12:46:42,412 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 56050
[junit] 2009-06-28 12:46:42,412 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 56050: exiting
[junit] 2009-06-28 12:46:42,413 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-28 12:46:42,413 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 5 on 56050: exiting
[junit] 2009-06-28 12:46:42,412 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 56050
[junit] 2009-06-28 12:46:42,412 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 7 on 56050: exiting
[junit] 2009-06-28 12:46:42,412 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 8 on 56050: exiting
[junit] 2009-06-28 12:46:42,412 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 4 on 56050: exiting
[junit] 2009-06-28 12:46:42,412 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 56050: exiting
[junit] 2009-06-28 12:46:42,413 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 56050: exiting
[junit] 2009-06-28 12:46:42,413 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 3 on 56050: exiting
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 126.93 sec
[junit] 2009-06-28 12:46:42,413 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 6 on 56050: exiting
[junit] 2009-06-28 12:46:42,413 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 9 on 56050: exiting
checkfailure:
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml
:571: Tests failed!
Total time: 72 minutes 50 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...
