See http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/4/changes
Changes:
[shv] HDFS-352. Documentation for saveNamespace command. Contributed by Ravi
Phulari.
[szetszwo] HDFS-181. Validate src path in FSNamesystem.getFileInfo(..).
Contributed by Todd Lipcon
[szetszwo] HDFS-444. Allow to change probability levels dynamically in the
fault injection framework. Contributed by Konstantin Boudnik
------------------------------------------
[...truncated 287329 lines...]
[junit] 2009-06-26 12:49:00,926 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-26 12:49:01,119 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-26 12:49:01,119 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-26 12:49:01,330 INFO mapred.JvmManager
(JvmManager.java:runChild(411)) - JVM : jvm_200906261247_0004_m_-1788316031
exited. Number of tasks it ran: 1
[junit] 2009-06-26 12:49:01,380 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-26 12:49:01,380 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 41323
[junit] 2009-06-26 12:49:01,380 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-26 12:49:01,381 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1246020929381 with
interval 21600000
[junit] 2009-06-26 12:49:01,382 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-26 12:49:01,383 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 60349
webServer.getConnectors()[0].getLocalPort() returned 60349
[junit] 2009-06-26 12:49:01,383 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 60349
[junit] 2009-06-26 12:49:01,383 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-26 12:49:01,448 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:60349
[junit] 2009-06-26 12:49:01,449 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-26 12:49:01,461 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=57930
[junit] 2009-06-26 12:49:01,462 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-26 12:49:01,462 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 57930: starting
[junit] 2009-06-26 12:49:01,462 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 57930: starting
[junit] 2009-06-26 12:49:01,464 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 57930: starting
[junit] 2009-06-26 12:49:01,463 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:41323, storageID=, infoPort=60349,
ipcPort=57930)
[junit] 2009-06-26 12:49:01,463 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 57930: starting
[junit] 2009-06-26 12:49:01,511 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1772)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:41323 storage
DS-864733044-67.195.138.9-41323-1246020541510
[junit] 2009-06-26 12:49:01,511 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:41323
[junit] 2009-06-26 12:49:01,555 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-864733044-67.195.138.9-41323-1246020541510 is assigned to data-node
127.0.0.1:41323
[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-26 12:49:01,556 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:41323,
storageID=DS-864733044-67.195.138.9-41323-1246020541510, infoPort=60349,
ipcPort=57930)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-26 12:49:01,556 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-26 12:49:01,567 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-26 12:49:01,568 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-26 12:49:01,596 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-06-26 12:49:01,597 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-26 12:49:01,744 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-26 12:49:01,745 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-26 12:49:02,036 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-26 12:49:02,037 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 49574
[junit] 2009-06-26 12:49:02,037 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-26 12:49:02,037 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1246036512037 with
interval 21600000
[junit] 2009-06-26 12:49:02,039 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-26 12:49:02,039 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 59075
webServer.getConnectors()[0].getLocalPort() returned 59075
[junit] 2009-06-26 12:49:02,039 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 59075
[junit] 2009-06-26 12:49:02,040 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-26 12:49:02,102 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:59075
[junit] 2009-06-26 12:49:02,102 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-26 12:49:02,114 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=57121
[junit] 2009-06-26 12:49:02,115 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-26 12:49:02,115 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 57121: starting
[junit] 2009-06-26 12:49:02,115 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:49574, storageID=, infoPort=59075,
ipcPort=57121)
[junit] 2009-06-26 12:49:02,115 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 57121: starting
[junit] 2009-06-26 12:49:02,115 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 57121: starting
[junit] 2009-06-26 12:49:02,115 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 57121: starting
[junit] 2009-06-26 12:49:02,117 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1772)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:49574 storage
DS-334819328-67.195.138.9-49574-1246020542116
[junit] 2009-06-26 12:49:02,118 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:49574
[junit] 2009-06-26 12:49:02,167 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-334819328-67.195.138.9-49574-1246020542116 is assigned to data-node
127.0.0.1:49574
[junit] 2009-06-26 12:49:02,167 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:49574,
storageID=DS-334819328-67.195.138.9-49574-1246020542116, infoPort=59075,
ipcPort=57121)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-26 12:49:02,168 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-26 12:49:02,179 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-26 12:49:02,180 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-26 12:49:02,217 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-06-26 12:49:02,217 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-26 12:49:02,350 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-26 12:49:02,350 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-26 12:49:02,636 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-26 12:49:02,636 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 54971
[junit] 2009-06-26 12:49:02,637 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-26 12:49:02,637 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1246028991637 with
interval 21600000
[junit] 2009-06-26 12:49:02,638 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-26 12:49:02,639 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 51128
webServer.getConnectors()[0].getLocalPort() returned 51128
[junit] 2009-06-26 12:49:02,639 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 51128
[junit] 2009-06-26 12:49:02,639 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-26 12:49:02,741 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:51128
[junit] 2009-06-26 12:49:02,744 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-26 12:49:02,756 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=60820
[junit] 2009-06-26 12:49:02,757 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-26 12:49:02,757 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 60820: starting
[junit] 2009-06-26 12:49:02,757 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 60820: starting
[junit] 2009-06-26 12:49:02,757 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 60820: starting
[junit] 2009-06-26 12:49:02,758 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:54971, storageID=, infoPort=51128,
ipcPort=60820)
[junit] 2009-06-26 12:49:02,757 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 60820: starting
[junit] 2009-06-26 12:49:02,761 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1772)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:54971 storage
DS-1932944622-67.195.138.9-54971-1246020542760
[junit] 2009-06-26 12:49:02,761 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:54971
[junit] 2009-06-26 12:49:02,804 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-1932944622-67.195.138.9-54971-1246020542760 is assigned to data-node
127.0.0.1:54971
[junit] 2009-06-26 12:49:02,804 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:54971,
storageID=DS-1932944622-67.195.138.9-54971-1246020542760, infoPort=51128,
ipcPort=60820)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-26 12:49:02,805 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-26 12:49:02,815 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-26 12:49:02,816 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-26 12:49:02,846 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-06-26 12:49:02,846 INFO datanode.DataNode
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
[junit] 2009-06-26 12:49:03,031 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-26 12:49:03,032 INFO common.Storage
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
[junit] 2009-06-26 12:49:03,310 INFO datanode.DataNode
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
[junit] 2009-06-26 12:49:03,311 INFO datanode.DataNode
(DataNode.java:startDataNode(326)) - Opened info server at 34548
[junit] 2009-06-26 12:49:03,311 INFO datanode.DataNode
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
[junit] 2009-06-26 12:49:03,311 INFO datanode.DirectoryScanner
(DirectoryScanner.java:<init>(133)) - scan starts at 1246022189311 with
interval 21600000
[junit] 2009-06-26 12:49:03,313 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-26 12:49:03,313 INFO http.HttpServer
(HttpServer.java:start(430)) - listener.getLocalPort() returned 43336
webServer.getConnectors()[0].getLocalPort() returned 43336
[junit] 2009-06-26 12:49:03,314 INFO http.HttpServer
(HttpServer.java:start(463)) - Jetty bound to port 43336
[junit] 2009-06-26 12:49:03,314 INFO mortbay.log (?:invoke(?)) -
jetty-6.1.14
[junit] 2009-06-26 12:49:03,503 INFO mortbay.log (?:invoke(?)) - Started
selectchannelconnec...@localhost:43336
[junit] 2009-06-26 12:49:03,504 INFO jvm.JvmMetrics
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2009-06-26 12:49:03,516 INFO metrics.RpcMetrics
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode,
port=55265
[junit] 2009-06-26 12:49:03,516 INFO ipc.Server (Server.java:run(474)) -
IPC Server Responder: starting
[junit] 2009-06-26 12:49:03,517 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 2 on 55265: starting
[junit] 2009-06-26 12:49:03,517 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 1 on 55265: starting
[junit] 2009-06-26 12:49:03,517 INFO ipc.Server (Server.java:run(939)) -
IPC Server handler 0 on 55265: starting
[junit] 2009-06-26 12:49:03,517 INFO ipc.Server (Server.java:run(313)) -
IPC Server listener on 55265: starting
[junit] 2009-06-26 12:49:03,517 INFO datanode.DataNode
(DataNode.java:startDataNode(404)) - dnRegistration =
DatanodeRegistration(vesta.apache.org:34548, storageID=, infoPort=43336,
ipcPort=55265)
[junit] 2009-06-26 12:49:03,523 INFO hdfs.StateChange
(FSNamesystem.java:registerDatanode(1772)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:34548 storage
DS-86204223-67.195.138.9-34548-1246020543523
[junit] 2009-06-26 12:49:03,524 INFO net.NetworkTopology
(NetworkTopology.java:add(327)) - Adding a new node:
/default-rack/127.0.0.1:34548
[junit] 2009-06-26 12:49:03,568 INFO datanode.DataNode
(DataNode.java:register(566)) - New storage id
DS-86204223-67.195.138.9-34548-1246020543523 is assigned to data-node
127.0.0.1:34548
[junit] 2009-06-26 12:49:03,569 INFO datanode.DataNode
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:34548,
storageID=DS-86204223-67.195.138.9-34548-1246020543523, infoPort=43336,
ipcPort=55265)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-26 12:49:03,576 INFO datanode.DataNode
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec
Initial delay: 0msec
[junit] 2009-06-26 12:49:03,627 INFO datanode.DataNode
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2009-06-26 12:49:03,627 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-26 12:49:03,668 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-26 12:49:03,783 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 55265
[junit] 2009-06-26 12:49:03,783 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 55265: exiting
[junit] 2009-06-26 12:49:03,784 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-26 12:49:03,784 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 55265: exiting
[junit] 2009-06-26 12:49:03,784 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-26 12:49:03,784 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 55265
[junit] 2009-06-26 12:49:03,783 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 55265: exiting
[junit] 2009-06-26 12:49:03,785 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:34548,
storageID=DS-86204223-67.195.138.9-34548-1246020543523, infoPort=43336,
ipcPort=55265):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-26 12:49:03,787 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-06-26 12:49:03,787 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-26 12:49:03,788 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:34548,
storageID=DS-86204223-67.195.138.9-34548-1246020543523, infoPort=43336,
ipcPort=55265):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-26 12:49:03,788 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 55265
[junit] 2009-06-26 12:49:03,788 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 2
[junit] 2009-06-26 12:49:03,890 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 60820
[junit] 2009-06-26 12:49:03,891 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 60820: exiting
[junit] 2009-06-26 12:49:03,891 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 60820: exiting
[junit] 2009-06-26 12:49:03,891 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 60820: exiting
[junit] 2009-06-26 12:49:03,891 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:54971,
storageID=DS-1932944622-67.195.138.9-54971-1246020542760, infoPort=51128,
ipcPort=60820):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-26 12:49:03,891 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-26 12:49:03,891 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-26 12:49:03,891 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 60820
[junit] 2009-06-26 12:49:03,892 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-26 12:49:03,893 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:54971,
storageID=DS-1932944622-67.195.138.9-54971-1246020542760, infoPort=51128,
ipcPort=60820):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-26 12:49:03,893 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 60820
[junit] 2009-06-26 12:49:03,893 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 1
[junit] 2009-06-26 12:49:03,995 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 57121
[junit] 2009-06-26 12:49:03,996 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 57121: exiting
[junit] 2009-06-26 12:49:03,996 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 57121: exiting
[junit] 2009-06-26 12:49:03,996 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 57121
[junit] 2009-06-26 12:49:03,997 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:49574,
storageID=DS-334819328-67.195.138.9-49574-1246020542116, infoPort=59075,
ipcPort=57121):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-26 12:49:03,997 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-26 12:49:03,997 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-26 12:49:03,996 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 57121: exiting
[junit] 2009-06-26 12:49:03,996 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-26 12:49:03,997 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:49574,
storageID=DS-334819328-67.195.138.9-49574-1246020542116, infoPort=59075,
ipcPort=57121):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-26 12:49:03,998 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 57121
[junit] 2009-06-26 12:49:03,998 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] Shutting down DataNode 0
[junit] 2009-06-26 12:49:04,133 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 57930
[junit] 2009-06-26 12:49:04,133 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 57930: exiting
[junit] 2009-06-26 12:49:04,133 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 57930: exiting
[junit] 2009-06-26 12:49:04,133 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 57930: exiting
[junit] 2009-06-26 12:49:04,134 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 57930
[junit] 2009-06-26 12:49:04,134 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2009-06-26 12:49:04,134 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-26 12:49:04,134 WARN datanode.DataNode
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:41323,
storageID=DS-864733044-67.195.138.9-41323-1246020541510, infoPort=60349,
ipcPort=57930):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-26 12:49:04,136 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-06-26 12:49:04,136 INFO datanode.DataBlockScanner
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
[junit] 2009-06-26 12:49:04,137 INFO datanode.DataNode
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:41323,
storageID=DS-864733044-67.195.138.9-41323-1246020541510, infoPort=60349,
ipcPort=57930):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-26 12:49:04,137 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 57930
[junit] 2009-06-26 12:49:04,137 INFO datanode.DataNode
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2009-06-26 12:49:04,239 WARN namenode.FSNamesystem
(FSNamesystem.java:run(2075)) - ReplicationMonitor thread received
InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 2009-06-26 12:49:04,239 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-26 12:49:04,239 WARN namenode.DecommissionManager
(DecommissionManager.java:run(67)) - Monitor interrupted:
java.lang.InterruptedException: sleep interrupted
[junit] 2009-06-26 12:49:04,365 INFO ipc.Server (Server.java:stop(1103)) -
Stopping server on 33272
[junit] 2009-06-26 12:49:04,365 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 0 on 33272: exiting
[junit] 2009-06-26 12:49:04,365 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 1 on 33272: exiting
[junit] 2009-06-26 12:49:04,365 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 2 on 33272: exiting
[junit] 2009-06-26 12:49:04,366 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 3 on 33272: exiting
[junit] 2009-06-26 12:49:04,366 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 4 on 33272: exiting
[junit] 2009-06-26 12:49:04,366 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 5 on 33272: exiting
[junit] 2009-06-26 12:49:04,366 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 6 on 33272: exiting
[junit] 2009-06-26 12:49:04,367 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 7 on 33272: exiting
[junit] 2009-06-26 12:49:04,367 INFO ipc.Server (Server.java:run(539)) -
Stopping IPC Server Responder
[junit] 2009-06-26 12:49:04,367 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 8 on 33272: exiting
[junit] 2009-06-26 12:49:04,367 INFO ipc.Server (Server.java:run(352)) -
Stopping IPC Server listener on 33272
[junit] 2009-06-26 12:49:04,367 INFO ipc.Server (Server.java:run(997)) -
IPC Server handler 9 on 33272: exiting
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 126.647 sec
checkfailure:
BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Hadoop-Hdfs-trunk/ws/trunk/build.xml
:571: Tests failed!
Total time: 75 minutes 10 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...
