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

------------------------------------------
[...truncated 292542 lines...]
    [junit] 2009-06-29 13:03:52,260 INFO  common.Storage 
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-06-29 13:03:52,473 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-29 13:03:52,473 INFO  common.Storage 
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-06-29 13:03:52,806 INFO  datanode.DataNode 
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
    [junit] 2009-06-29 13:03:52,807 INFO  datanode.DataNode 
(DataNode.java:startDataNode(326)) - Opened info server at 42708
    [junit] 2009-06-29 13:03:52,807 INFO  datanode.DataNode 
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2009-06-29 13:03:52,807 INFO  datanode.DirectoryScanner 
(DirectoryScanner.java:<init>(133)) - scan starts at 1246299803807 with 
interval 21600000
    [junit] 2009-06-29 13:03:52,809 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-29 13:03:52,809 INFO  http.HttpServer 
(HttpServer.java:start(430)) - listener.getLocalPort() returned 45556 
webServer.getConnectors()[0].getLocalPort() returned 45556
    [junit] 2009-06-29 13:03:52,809 INFO  http.HttpServer 
(HttpServer.java:start(463)) - Jetty bound to port 45556
    [junit] 2009-06-29 13:03:52,809 INFO  mortbay.log (?:invoke(?)) - 
jetty-6.1.14
    [junit] 2009-06-29 13:03:52,885 INFO  mortbay.log (?:invoke(?)) - Started 
selectchannelconnec...@localhost:45556
    [junit] 2009-06-29 13:03:52,886 INFO  jvm.JvmMetrics 
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with 
processName=DataNode, sessionId=null - already initialized
    [junit] 2009-06-29 13:03:52,899 INFO  metrics.RpcMetrics 
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, 
port=39753
    [junit] 2009-06-29 13:03:52,900 INFO  ipc.Server (Server.java:run(474)) - 
IPC Server Responder: starting
    [junit] 2009-06-29 13:03:52,900 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 0 on 39753: starting
    [junit] 2009-06-29 13:03:52,900 INFO  ipc.Server (Server.java:run(313)) - 
IPC Server listener on 39753: starting
    [junit] 2009-06-29 13:03:52,901 INFO  datanode.DataNode 
(DataNode.java:startDataNode(404)) - dnRegistration = 
DatanodeRegistration(vesta.apache.org:42708, storageID=, infoPort=45556, 
ipcPort=39753)
    [junit] 2009-06-29 13:03:52,901 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 2 on 39753: starting
    [junit] 2009-06-29 13:03:52,913 INFO  hdfs.StateChange 
(FSNamesystem.java:registerDatanode(1772)) - BLOCK* 
NameSystem.registerDatanode: node registration from 127.0.0.1:42708 storage 
DS-1722747606-67.195.138.9-42708-1246280632901
    [junit] 2009-06-29 13:03:52,913 INFO  net.NetworkTopology 
(NetworkTopology.java:add(327)) - Adding a new node: 
/default-rack/127.0.0.1:42708
    [junit] 2009-06-29 13:03:52,914 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 1 on 39753: starting
    [junit] 2009-06-29 13:03:52,983 INFO  datanode.DataNode 
(DataNode.java:register(566)) - New storage id 
DS-1722747606-67.195.138.9-42708-1246280632901 is assigned to data-node 
127.0.0.1:42708
    [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-29 13:03:52,983 INFO  datanode.DataNode 
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:42708, 
storageID=DS-1722747606-67.195.138.9-42708-1246280632901, infoPort=45556, 
ipcPort=39753)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-29 13:03:52,984 INFO  datanode.DataNode 
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec 
Initial delay: 0msec
    [junit] 2009-06-29 13:03:52,993 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-29 13:03:52,994 INFO  common.Storage 
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-06-29 13:03:53,025 INFO  datanode.DataNode 
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1 
msecs
    [junit] 2009-06-29 13:03:53,026 INFO  datanode.DataNode 
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
    [junit] 2009-06-29 13:03:53,186 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-29 13:03:53,187 INFO  common.Storage 
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-06-29 13:03:53,330 INFO  mapred.JvmManager 
(JvmManager.java:runChild(411)) - JVM : jvm_200906291301_0004_m_-186643344 
exited. Number of tasks it ran: 1
    [junit] 2009-06-29 13:03:53,478 INFO  datanode.DataNode 
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
    [junit] 2009-06-29 13:03:53,478 INFO  datanode.DataNode 
(DataNode.java:startDataNode(326)) - Opened info server at 42506
    [junit] 2009-06-29 13:03:53,479 INFO  datanode.DataNode 
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2009-06-29 13:03:53,479 INFO  datanode.DirectoryScanner 
(DirectoryScanner.java:<init>(133)) - scan starts at 1246289197479 with 
interval 21600000
    [junit] 2009-06-29 13:03:53,480 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-29 13:03:53,481 INFO  http.HttpServer 
(HttpServer.java:start(430)) - listener.getLocalPort() returned 32786 
webServer.getConnectors()[0].getLocalPort() returned 32786
    [junit] 2009-06-29 13:03:53,481 INFO  http.HttpServer 
(HttpServer.java:start(463)) - Jetty bound to port 32786
    [junit] 2009-06-29 13:03:53,481 INFO  mortbay.log (?:invoke(?)) - 
jetty-6.1.14
    [junit] 2009-06-29 13:03:53,543 INFO  mortbay.log (?:invoke(?)) - Started 
selectchannelconnec...@localhost:32786
    [junit] 2009-06-29 13:03:53,544 INFO  jvm.JvmMetrics 
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with 
processName=DataNode, sessionId=null - already initialized
    [junit] 2009-06-29 13:03:53,556 INFO  metrics.RpcMetrics 
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, 
port=35584
    [junit] 2009-06-29 13:03:53,557 INFO  ipc.Server (Server.java:run(474)) - 
IPC Server Responder: starting
    [junit] 2009-06-29 13:03:53,557 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 0 on 35584: starting
    [junit] 2009-06-29 13:03:53,558 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 2 on 35584: starting
    [junit] 2009-06-29 13:03:53,558 INFO  datanode.DataNode 
(DataNode.java:startDataNode(404)) - dnRegistration = 
DatanodeRegistration(vesta.apache.org:42506, storageID=, infoPort=32786, 
ipcPort=35584)
    [junit] 2009-06-29 13:03:53,557 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 1 on 35584: starting
    [junit] 2009-06-29 13:03:53,557 INFO  ipc.Server (Server.java:run(313)) - 
IPC Server listener on 35584: starting
    [junit] 2009-06-29 13:03:53,560 INFO  hdfs.StateChange 
(FSNamesystem.java:registerDatanode(1772)) - BLOCK* 
NameSystem.registerDatanode: node registration from 127.0.0.1:42506 storage 
DS-715876046-67.195.138.9-42506-1246280633559
    [junit] 2009-06-29 13:03:53,560 INFO  net.NetworkTopology 
(NetworkTopology.java:add(327)) - Adding a new node: 
/default-rack/127.0.0.1:42506
    [junit] 2009-06-29 13:03:53,609 INFO  datanode.DataNode 
(DataNode.java:register(566)) - New storage id 
DS-715876046-67.195.138.9-42506-1246280633559 is assigned to data-node 
127.0.0.1:42506
    [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-29 13:03:53,610 INFO  datanode.DataNode 
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:42506, 
storageID=DS-715876046-67.195.138.9-42506-1246280633559, infoPort=32786, 
ipcPort=35584)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-29 13:03:53,611 INFO  datanode.DataNode 
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec 
Initial delay: 0msec
    [junit] 2009-06-29 13:03:53,661 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-29 13:03:53,662 INFO  common.Storage 
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-06-29 13:03:53,683 INFO  datanode.DataNode 
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1 
msecs
    [junit] 2009-06-29 13:03:53,683 INFO  datanode.DataNode 
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
    [junit] 2009-06-29 13:03:53,861 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-29 13:03:53,861 INFO  common.Storage 
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-06-29 13:03:54,138 INFO  datanode.DataNode 
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
    [junit] 2009-06-29 13:03:54,138 INFO  datanode.DataNode 
(DataNode.java:startDataNode(326)) - Opened info server at 37785
    [junit] 2009-06-29 13:03:54,139 INFO  datanode.DataNode 
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2009-06-29 13:03:54,139 INFO  datanode.DirectoryScanner 
(DirectoryScanner.java:<init>(133)) - scan starts at 1246296536139 with 
interval 21600000
    [junit] 2009-06-29 13:03:54,140 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-29 13:03:54,140 INFO  http.HttpServer 
(HttpServer.java:start(430)) - listener.getLocalPort() returned 39307 
webServer.getConnectors()[0].getLocalPort() returned 39307
    [junit] 2009-06-29 13:03:54,141 INFO  http.HttpServer 
(HttpServer.java:start(463)) - Jetty bound to port 39307
    [junit] 2009-06-29 13:03:54,141 INFO  mortbay.log (?:invoke(?)) - 
jetty-6.1.14
    [junit] 2009-06-29 13:03:54,208 INFO  mortbay.log (?:invoke(?)) - Started 
selectchannelconnec...@localhost:39307
    [junit] 2009-06-29 13:03:54,209 INFO  jvm.JvmMetrics 
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with 
processName=DataNode, sessionId=null - already initialized
    [junit] 2009-06-29 13:03:54,220 INFO  metrics.RpcMetrics 
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, 
port=39231
    [junit] 2009-06-29 13:03:54,221 INFO  ipc.Server (Server.java:run(474)) - 
IPC Server Responder: starting
    [junit] 2009-06-29 13:03:54,221 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 1 on 39231: starting
    [junit] 2009-06-29 13:03:54,222 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 2 on 39231: starting
    [junit] 2009-06-29 13:03:54,221 INFO  datanode.DataNode 
(DataNode.java:startDataNode(404)) - dnRegistration = 
DatanodeRegistration(vesta.apache.org:37785, storageID=, infoPort=39307, 
ipcPort=39231)
    [junit] 2009-06-29 13:03:54,221 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 0 on 39231: starting
    [junit] 2009-06-29 13:03:54,223 INFO  hdfs.StateChange 
(FSNamesystem.java:registerDatanode(1772)) - BLOCK* 
NameSystem.registerDatanode: node registration from 127.0.0.1:37785 storage 
DS-505139630-67.195.138.9-37785-1246280634223
    [junit] 2009-06-29 13:03:54,224 INFO  net.NetworkTopology 
(NetworkTopology.java:add(327)) - Adding a new node: 
/default-rack/127.0.0.1:37785
    [junit] 2009-06-29 13:03:54,221 INFO  ipc.Server (Server.java:run(313)) - 
IPC Server listener on 39231: starting
    [junit] 2009-06-29 13:03:54,293 INFO  datanode.DataNode 
(DataNode.java:register(566)) - New storage id 
DS-505139630-67.195.138.9-37785-1246280634223 is assigned to data-node 
127.0.0.1:37785
    [junit] 2009-06-29 13:03:54,294 INFO  datanode.DataNode 
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:37785, 
storageID=DS-505139630-67.195.138.9-37785-1246280634223, infoPort=39307, 
ipcPort=39231)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-29 13:03:54,296 INFO  datanode.DataNode 
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec 
Initial delay: 0msec
    [junit] 2009-06-29 13:03:54,307 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-29 13:03:54,307 INFO  common.Storage 
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-06-29 13:03:54,341 INFO  datanode.DataNode 
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 0 
msecs
    [junit] 2009-06-29 13:03:54,342 INFO  datanode.DataNode 
(DataNode.java:offerService(777)) - Starting Periodic block scanner.
    [junit] 2009-06-29 13:03:54,508 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-29 13:03:54,509 INFO  common.Storage 
(DataStorage.java:recoverTransitionRead(123)) - Formatting ...
    [junit] 2009-06-29 13:03:54,770 INFO  datanode.DataNode 
(FSDataset.java:registerMBean(1417)) - Registered FSDatasetStatusMBean
    [junit] 2009-06-29 13:03:54,771 INFO  datanode.DataNode 
(DataNode.java:startDataNode(326)) - Opened info server at 45244
    [junit] 2009-06-29 13:03:54,771 INFO  datanode.DataNode 
(DataXceiverServer.java:<init>(74)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2009-06-29 13:03:54,772 INFO  datanode.DirectoryScanner 
(DirectoryScanner.java:<init>(133)) - scan starts at 1246282400772 with 
interval 21600000
    [junit] 2009-06-29 13:03:54,773 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-29 13:03:54,773 INFO  http.HttpServer 
(HttpServer.java:start(430)) - listener.getLocalPort() returned 59519 
webServer.getConnectors()[0].getLocalPort() returned 59519
    [junit] 2009-06-29 13:03:54,774 INFO  http.HttpServer 
(HttpServer.java:start(463)) - Jetty bound to port 59519
    [junit] 2009-06-29 13:03:54,774 INFO  mortbay.log (?:invoke(?)) - 
jetty-6.1.14
    [junit] 2009-06-29 13:03:54,922 INFO  mortbay.log (?:invoke(?)) - Started 
selectchannelconnec...@localhost:59519
    [junit] 2009-06-29 13:03:54,924 INFO  jvm.JvmMetrics 
(JvmMetrics.java:init(66)) - Cannot initialize JVM Metrics with 
processName=DataNode, sessionId=null - already initialized
    [junit] 2009-06-29 13:03:54,935 INFO  metrics.RpcMetrics 
(RpcMetrics.java:<init>(58)) - Initializing RPC Metrics with hostName=DataNode, 
port=36610
    [junit] 2009-06-29 13:03:54,936 INFO  ipc.Server (Server.java:run(474)) - 
IPC Server Responder: starting
    [junit] 2009-06-29 13:03:54,936 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 1 on 36610: starting
    [junit] 2009-06-29 13:03:54,940 INFO  datanode.DataNode 
(DataNode.java:startDataNode(404)) - dnRegistration = 
DatanodeRegistration(vesta.apache.org:45244, storageID=, infoPort=59519, 
ipcPort=36610)
    [junit] 2009-06-29 13:03:54,940 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 2 on 36610: starting
    [junit] 2009-06-29 13:03:54,936 INFO  ipc.Server (Server.java:run(939)) - 
IPC Server handler 0 on 36610: starting
    [junit] 2009-06-29 13:03:54,936 INFO  ipc.Server (Server.java:run(313)) - 
IPC Server listener on 36610: starting
    [junit] 2009-06-29 13:03:54,942 INFO  hdfs.StateChange 
(FSNamesystem.java:registerDatanode(1772)) - BLOCK* 
NameSystem.registerDatanode: node registration from 127.0.0.1:45244 storage 
DS-2074316479-67.195.138.9-45244-1246280634941
    [junit] 2009-06-29 13:03:54,942 INFO  net.NetworkTopology 
(NetworkTopology.java:add(327)) - Adding a new node: 
/default-rack/127.0.0.1:45244
    [junit] 2009-06-29 13:03:54,986 INFO  datanode.DataNode 
(DataNode.java:register(566)) - New storage id 
DS-2074316479-67.195.138.9-45244-1246280634941 is assigned to data-node 
127.0.0.1:45244
    [junit] 2009-06-29 13:03:54,986 INFO  datanode.DataNode 
(DataNode.java:run(1253)) - DatanodeRegistration(127.0.0.1:45244, 
storageID=DS-2074316479-67.195.138.9-45244-1246280634941, infoPort=59519, 
ipcPort=36610)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-29 13:03:54,992 INFO  datanode.DataNode 
(DataNode.java:offerService(734)) - using BLOCKREPORT_INTERVAL of 21600000msec 
Initial delay: 0msec
    [junit] 2009-06-29 13:03:55,054 INFO  datanode.DataNode 
(DataNode.java:blockReport(969)) - BlockReport of 0 blocks got processed in 1 
msecs
    [junit] 2009-06-29 13:03:55,055 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-29 13:03:55,102 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-29 13:03:55,206 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 36610
    [junit] 2009-06-29 13:03:55,206 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 0 on 36610: exiting
    [junit] 2009-06-29 13:03:55,206 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 2 on 36610: exiting
    [junit] 2009-06-29 13:03:55,207 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 1 on 36610: exiting
    [junit] 2009-06-29 13:03:55,207 INFO  ipc.Server (Server.java:run(352)) - 
Stopping IPC Server listener on 36610
    [junit] 2009-06-29 13:03:55,207 INFO  ipc.Server (Server.java:run(539)) - 
Stopping IPC Server Responder
    [junit] 2009-06-29 13:03:55,208 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 1
    [junit] 2009-06-29 13:03:55,208 WARN  datanode.DataNode 
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:45244, 
storageID=DS-2074316479-67.195.138.9-45244-1246280634941, infoPort=59519, 
ipcPort=36610):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-29 13:03:55,210 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 0
    [junit] 2009-06-29 13:03:55,211 INFO  datanode.DataBlockScanner 
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-06-29 13:03:55,211 INFO  datanode.DataNode 
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:45244, 
storageID=DS-2074316479-67.195.138.9-45244-1246280634941, infoPort=59519, 
ipcPort=36610):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-29 13:03:55,211 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 36610
    [junit] 2009-06-29 13:03:55,212 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 0
    [junit] Shutting down DataNode 2
    [junit] 2009-06-29 13:03:55,314 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 39231
    [junit] 2009-06-29 13:03:55,314 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 0 on 39231: exiting
    [junit] 2009-06-29 13:03:55,314 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 1 on 39231: exiting
    [junit] 2009-06-29 13:03:55,314 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 2 on 39231: exiting
    [junit] 2009-06-29 13:03:55,314 INFO  ipc.Server (Server.java:run(352)) - 
Stopping IPC Server listener on 39231
    [junit] 2009-06-29 13:03:55,315 WARN  datanode.DataNode 
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:37785, 
storageID=DS-505139630-67.195.138.9-37785-1246280634223, infoPort=39307, 
ipcPort=39231):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-29 13:03:55,315 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 1
    [junit] 2009-06-29 13:03:55,315 INFO  ipc.Server (Server.java:run(539)) - 
Stopping IPC Server Responder
    [junit] 2009-06-29 13:03:55,316 INFO  datanode.DataBlockScanner 
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-06-29 13:03:55,316 INFO  datanode.DataNode 
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:37785, 
storageID=DS-505139630-67.195.138.9-37785-1246280634223, infoPort=39307, 
ipcPort=39231):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-29 13:03:55,316 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 39231
    [junit] 2009-06-29 13:03:55,317 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 0
    [junit] Shutting down DataNode 1
    [junit] 2009-06-29 13:03:55,419 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 35584
    [junit] 2009-06-29 13:03:55,419 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 0 on 35584: exiting
    [junit] 2009-06-29 13:03:55,420 INFO  ipc.Server (Server.java:run(352)) - 
Stopping IPC Server listener on 35584
    [junit] 2009-06-29 13:03:55,420 WARN  datanode.DataNode 
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:42506, 
storageID=DS-715876046-67.195.138.9-42506-1246280633559, infoPort=32786, 
ipcPort=35584):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-29 13:03:55,420 INFO  ipc.Server (Server.java:run(539)) - 
Stopping IPC Server Responder
    [junit] 2009-06-29 13:03:55,419 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 2 on 35584: exiting
    [junit] 2009-06-29 13:03:55,420 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 1
    [junit] 2009-06-29 13:03:55,420 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 1 on 35584: exiting
    [junit] 2009-06-29 13:03:55,421 INFO  datanode.DataBlockScanner 
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-06-29 13:03:55,421 INFO  datanode.DataNode 
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:42506, 
storageID=DS-715876046-67.195.138.9-42506-1246280633559, infoPort=32786, 
ipcPort=35584):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-29 13:03:55,421 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 35584
    [junit] 2009-06-29 13:03:55,421 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 0
    [junit] Shutting down DataNode 0
    [junit] 2009-06-29 13:03:55,523 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 39753
    [junit] 2009-06-29 13:03:55,524 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 0 on 39753: exiting
    [junit] 2009-06-29 13:03:55,524 INFO  ipc.Server (Server.java:run(352)) - 
Stopping IPC Server listener on 39753
    [junit] 2009-06-29 13:03:55,524 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 1
    [junit] 2009-06-29 13:03:55,524 INFO  ipc.Server (Server.java:run(539)) - 
Stopping IPC Server Responder
    [junit] 2009-06-29 13:03:55,525 WARN  datanode.DataNode 
(DataXceiverServer.java:run(137)) - DatanodeRegistration(127.0.0.1:42708, 
storageID=DS-1722747606-67.195.138.9-42708-1246280632901, infoPort=45556, 
ipcPort=39753):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-29 13:03:55,525 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 1 on 39753: exiting
    [junit] 2009-06-29 13:03:55,525 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 2 on 39753: exiting
    [junit] 2009-06-29 13:03:55,527 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 0
    [junit] 2009-06-29 13:03:55,527 INFO  datanode.DataBlockScanner 
(DataBlockScanner.java:run(616)) - Exiting DataBlockScanner thread.
    [junit] 2009-06-29 13:03:55,527 INFO  datanode.DataNode 
(DataNode.java:run(1273)) - DatanodeRegistration(127.0.0.1:42708, 
storageID=DS-1722747606-67.195.138.9-42708-1246280632901, infoPort=45556, 
ipcPort=39753):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-29 13:03:55,527 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 39753
    [junit] 2009-06-29 13:03:55,528 INFO  datanode.DataNode 
(DataNode.java:shutdown(638)) - Waiting for threadgroup to exit, active threads 
is 0
    [junit] 2009-06-29 13:03:55,630 WARN  namenode.DecommissionManager 
(DecommissionManager.java:run(67)) - Monitor interrupted: 
java.lang.InterruptedException: sleep interrupted
    [junit] 2009-06-29 13:03:55,630 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-29 13:03:55,630 WARN  namenode.FSNamesystem 
(FSNamesystem.java:run(2075)) - ReplicationMonitor thread received 
InterruptedException.java.lang.InterruptedException: sleep interrupted
    [junit] 2009-06-29 13:03:55,732 INFO  ipc.Server (Server.java:stop(1103)) - 
Stopping server on 47186
    [junit] 2009-06-29 13:03:55,732 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 0 on 47186: exiting
    [junit] 2009-06-29 13:03:55,732 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 1 on 47186: exiting
    [junit] 2009-06-29 13:03:55,732 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 2 on 47186: exiting
    [junit] 2009-06-29 13:03:55,733 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 3 on 47186: exiting
    [junit] 2009-06-29 13:03:55,733 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 4 on 47186: exiting
    [junit] 2009-06-29 13:03:55,733 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 5 on 47186: exiting
    [junit] 2009-06-29 13:03:55,733 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 7 on 47186: exiting
    [junit] 2009-06-29 13:03:55,733 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 8 on 47186: exiting
    [junit] 2009-06-29 13:03:55,733 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 9 on 47186: exiting
    [junit] 2009-06-29 13:03:55,734 INFO  ipc.Server (Server.java:run(997)) - 
IPC Server handler 6 on 47186: exiting
    [junit] 2009-06-29 13:03:55,734 INFO  ipc.Server (Server.java:run(539)) - 
Stopping IPC Server Responder
    [junit] 2009-06-29 13:03:55,734 INFO  ipc.Server (Server.java:run(352)) - 
Stopping IPC Server listener on 47186
    [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 149.267 sec

checkfailure:

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

Total time: 90 minutes 25 seconds
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...

Reply via email to