See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/456/changes

Changes:

[cdouglas] HADOOP-3208. Fix WritableDeserializer to set the Configuration on
deserialized Writables. Contributed by Enis Soztutar.

[cdouglas] HADOOP-3143. Decrease number of slaves from 4 to 3 in 
TestMiniMRDFSSort, as
Hudson generates false negatives under the current load. Contributed by Nigel
Daley.

[shv] HADOOP-3220. Safemode message corrected. Contributed by Konstantin 
Shvachko.

[shv] HADOOP-3069. Primary name-node should not truncate image when transfering 
it from the secondary. Contributed by Konstantin Shvachko.

[rangadi] HADOOP-3175. Fix FsShell.CommandFormat to handle - in arguments. 
(Edward J. Yoon via rangadi)

------------------------------------------
[...truncated 101100 lines...]
    [junit] 2008-04-10 12:22:38,937 INFO  dfs.Storage 
(DataStorage.java:recoverTransitionRead(117)) - Storage directory 
/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data3
 is not formatted.
    [junit] 2008-04-10 12:22:38,938 INFO  dfs.Storage 
(DataStorage.java:recoverTransitionRead(118)) - Formatting ...
    [junit] 2008-04-10 12:22:39,356 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:39,357 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:39,905 INFO  dfs.Storage 
(DataStorage.java:recoverTransitionRead(117)) - Storage directory 
/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data4
 is not formatted.
    [junit] 2008-04-10 12:22:39,905 INFO  dfs.Storage 
(DataStorage.java:recoverTransitionRead(118)) - Formatting ...
    [junit] 2008-04-10 12:22:40,340 INFO  dfs.DataNode 
(FSDataset.java:registerMBean(975)) - Registered FSDatasetStatusMBean
    [junit] 2008-04-10 12:22:40,341 INFO  dfs.DataNode 
(DataNode.java:startDataNode(268)) - Opened server at 41105
    [junit] 2008-04-10 12:22:40,341 INFO  dfs.DataNode 
(DataNode.java:startDataNode(288)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2008-04-10 12:22:40,412 INFO  http.HttpServer 
(HttpServer.java:doStart(729)) - Version Jetty/5.1.4
    [junit] 2008-04-10 12:22:40,534 INFO  util.Container 
(Container.java:start(74)) - Started [EMAIL PROTECTED]
    [junit] 2008-04-10 12:22:40,537 INFO  util.Container 
(Container.java:start(74)) - Started WebApplicationContext[/,/]
    [junit] 2008-04-10 12:22:40,537 INFO  util.Container 
(Container.java:start(74)) - Started HttpContext[/logs,/logs]
    [junit] 2008-04-10 12:22:40,538 INFO  util.Container 
(Container.java:start(74)) - Started HttpContext[/static,/static]
    [junit] 2008-04-10 12:22:40,539 INFO  http.SocketListener 
(SocketListener.java:start(204)) - Started SocketListener on 127.0.0.1:41106
    [junit] 2008-04-10 12:22:40,539 INFO  util.Container 
(Container.java:start(74)) - Started [EMAIL PROTECTED]
    [junit] 2008-04-10 12:22:40,540 INFO  jvm.JvmMetrics 
(JvmMetrics.java:init(62)) - Cannot initialize JVM Metrics with 
processName=DataNode, sessionId=null - already initialized
    [junit] 2008-04-10 12:22:40,543 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:40,544 INFO  dfs.StateChange 
(FSNamesystem.java:registerDatanode(2018)) - BLOCK* 
NameSystem.registerDatanode: node registration from 127.0.0.1:41105 storage 
DS-81040587-140.211.11.106-41105-1207830160543
    [junit] 2008-04-10 12:22:40,544 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:40,544 INFO  net.NetworkTopology 
(NetworkTopology.java:add(321)) - Adding a new node: 
/default-rack/127.0.0.1:41105
    [junit] 2008-04-10 12:22:40,621 INFO  dfs.DataNode 
(DataNode.java:register(461)) - New storage id 
DS-81040587-140.211.11.106-41105-1207830160543 is assigned to data-node 
127.0.0.1:41105
    [junit] Starting DataNode 2 with dfs.data.dir: 
/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data5,/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data6
    [junit] 2008-04-10 12:22:40,623 INFO  dfs.DataNode 
(DataNode.java:run(2641)) - 127.0.0.1:41105In DataNode.run, data = 
FSDataset{dirpath='/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data3/current,/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data4/current'}
    [junit] 2008-04-10 12:22:40,623 INFO  dfs.DataNode 
(DataNode.java:offerService(583)) - using BLOCKREPORT_INTERVAL of 3600000msec 
Initial delay: 0msec
    [junit] 2008-04-10 12:22:40,653 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:40,654 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:40,657 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:40,657 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:40,659 INFO  dfs.Storage 
(DataStorage.java:recoverTransitionRead(117)) - Storage directory 
/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data5
 is not formatted.
    [junit] 2008-04-10 12:22:40,659 INFO  dfs.Storage 
(DataStorage.java:recoverTransitionRead(118)) - Formatting ...
    [junit] 2008-04-10 12:22:40,838 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:40,840 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:41,033 INFO  dfs.Storage 
(DataStorage.java:recoverTransitionRead(117)) - Storage directory 
/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data6
 is not formatted.
    [junit] 2008-04-10 12:22:41,033 INFO  dfs.Storage 
(DataStorage.java:recoverTransitionRead(118)) - Formatting ...
    [junit] 2008-04-10 12:22:41,534 INFO  dfs.DataNode 
(FSDataset.java:registerMBean(975)) - Registered FSDatasetStatusMBean
    [junit] 2008-04-10 12:22:41,535 INFO  dfs.DataNode 
(DataNode.java:startDataNode(268)) - Opened server at 41107
    [junit] 2008-04-10 12:22:41,536 INFO  dfs.DataNode 
(DataNode.java:startDataNode(288)) - Balancing bandwith is 1048576 bytes/s
    [junit] 2008-04-10 12:22:41,557 INFO  http.HttpServer 
(HttpServer.java:doStart(729)) - Version Jetty/5.1.4
    [junit] 2008-04-10 12:22:41,679 INFO  util.Container 
(Container.java:start(74)) - Started [EMAIL PROTECTED]
    [junit] 2008-04-10 12:22:41,681 INFO  util.Container 
(Container.java:start(74)) - Started WebApplicationContext[/,/]
    [junit] 2008-04-10 12:22:41,682 INFO  util.Container 
(Container.java:start(74)) - Started HttpContext[/logs,/logs]
    [junit] 2008-04-10 12:22:41,682 INFO  util.Container 
(Container.java:start(74)) - Started HttpContext[/static,/static]
    [junit] 2008-04-10 12:22:41,685 INFO  http.SocketListener 
(SocketListener.java:start(204)) - Started SocketListener on 127.0.0.1:41108
    [junit] 2008-04-10 12:22:41,685 INFO  util.Container 
(Container.java:start(74)) - Started [EMAIL PROTECTED]
    [junit] 2008-04-10 12:22:41,686 INFO  jvm.JvmMetrics 
(JvmMetrics.java:init(62)) - Cannot initialize JVM Metrics with 
processName=DataNode, sessionId=null - already initialized
    [junit] 2008-04-10 12:22:41,690 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 4 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:41,690 INFO  dfs.StateChange 
(FSNamesystem.java:registerDatanode(2018)) - BLOCK* 
NameSystem.registerDatanode: node registration from 127.0.0.1:41107 storage 
DS-1701659407-140.211.11.106-41107-1207830161689
    [junit] 2008-04-10 12:22:41,691 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 4 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:41,692 INFO  net.NetworkTopology 
(NetworkTopology.java:add(321)) - Adding a new node: 
/default-rack/127.0.0.1:41107
    [junit] 2008-04-10 12:22:41,848 INFO  dfs.DataNode 
(DataNode.java:register(461)) - New storage id 
DS-1701659407-140.211.11.106-41107-1207830161689 is assigned to data-node 
127.0.0.1:41107
    [junit] 2008-04-10 12:22:41,849 INFO  dfs.DataNode 
(DataNode.java:run(2641)) - 127.0.0.1:41107In DataNode.run, data = 
FSDataset{dirpath='/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data5/current,/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data6/current'}
    [junit] 2008-04-10 12:22:41,850 INFO  dfs.DataNode 
(DataNode.java:offerService(583)) - using BLOCKREPORT_INTERVAL of 3600000msec 
Initial delay: 0msec
    [junit] 2008-04-10 12:22:41,873 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 1 on 41099, 
ugi=hudson,hudson
    [junit] 2008-04-10 12:22:41,875 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 1 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:41,878 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 5 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:41,879 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 5 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:41,882 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 7 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:41,883 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 7 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:41,884 INFO  dfs.DataNode 
(DataNode.java:offerService(665)) - BlockReport of 0 blocks got processed in 5 
msecs
    [junit] 2008-04-10 12:22:41,886 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 41099, 
ugi=hudson,hudson
    [junit] 2008-04-10 12:22:41,887 DEBUG security.UserGroupInformation 
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
    [junit] 2008-04-10 12:22:41,888 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:42,007 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:42,008 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:42,895 DEBUG security.UserGroupInformation 
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
    [junit] 2008-04-10 12:22:42,897 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 41099, 
ugi=hudson,hudson
    [junit] 2008-04-10 12:22:42,898 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:42,899 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 41099, 
ugi=hudson,hudson
    [junit] 2008-04-10 12:22:42,899 DEBUG security.UserGroupInformation 
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
    [junit] 2008-04-10 12:22:42,900 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:43,625 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:43,626 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:43,627 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:43,628 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:43,628 INFO  dfs.DataNode 
(DataNode.java:offerService(665)) - BlockReport of 0 blocks got processed in 2 
msecs
    [junit] 2008-04-10 12:22:43,906 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 4 on 41099, 
ugi=hudson,hudson
    [junit] 2008-04-10 12:22:43,906 DEBUG security.UserGroupInformation 
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
    [junit] 2008-04-10 12:22:43,911 INFO  ipc.Server (Server.java:run(898)) - 
IPC Server handler 4 on 41099, call getFileInfo(/data/file1) from 
127.0.0.1:41109: error: java.io.FileNotFoundException: File does not exist: 
/data/file1
    [junit] java.io.FileNotFoundException: File does not exist: /data/file1
    [junit]     at 
org.apache.hadoop.dfs.FSDirectory.getFileInfo(FSDirectory.java:578)
    [junit]     at 
org.apache.hadoop.dfs.FSNamesystem.getFileInfo(FSNamesystem.java:1565)
    [junit]     at org.apache.hadoop.dfs.NameNode.getFileInfo(NameNode.java:444)
    [junit]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    [junit]     at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    [junit]     at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    [junit]     at java.lang.reflect.Method.invoke(Method.java:585)
    [junit]     at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:446)
    [junit]     at org.apache.hadoop.ipc.Server$Handler.run(Server.java:896)
    [junit] 2008-04-10 12:22:43,912 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 4 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:43,916 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 1 on 41099, 
ugi=hudson,hudson
    [junit] 2008-04-10 12:22:43,916 DEBUG security.UserGroupInformation 
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
    [junit] 2008-04-10 12:22:43,916 INFO  ipc.Server (Server.java:run(898)) - 
IPC Server handler 1 on 41099, call setOwner(/data/file1, foo, bar) from 
127.0.0.1:41109: error: java.io.FileNotFoundException: File does not exist: 
/data/file1
    [junit] java.io.FileNotFoundException: File does not exist: /data/file1
    [junit]     at 
org.apache.hadoop.dfs.FSDirectory.unprotectedSetOwner(FSDirectory.java:437)
    [junit]     at 
org.apache.hadoop.dfs.FSDirectory.setOwner(FSDirectory.java:429)
    [junit]     at 
org.apache.hadoop.dfs.FSNamesystem.setOwner(FSNamesystem.java:774)
    [junit]     at org.apache.hadoop.dfs.NameNode.setOwner(NameNode.java:291)
    [junit]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    [junit]     at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    [junit]     at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    [junit]     at java.lang.reflect.Method.invoke(Method.java:585)
    [junit]     at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:446)
    [junit]     at org.apache.hadoop.ipc.Server$Handler.run(Server.java:896)
    [junit] 2008-04-10 12:22:43,917 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 1 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:43,917 INFO  security.TestPermission 
(TestPermission.java:testFilePermision(135)) - GOOD: got 
java.io.FileNotFoundException
    [junit] 2008-04-10 12:22:43,918 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 5 on 41099, 
ugi=hudson,hudson
    [junit] 2008-04-10 12:22:43,918 DEBUG security.UserGroupInformation 
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
    [junit] 2008-04-10 12:23:54,693 INFO  ipc.Server (Server.java:run(898)) - 
IPC Server handler 5 on 41099, call setPermission(/data/file1, rwxrwxrwx) from 
127.0.0.1:41109: error: java.io.FileNotFoundException: File does not exist: 
/data/file1
    [junit] java.io.FileNotFoundException: File does not exist: /data/file1
    [junit]     at 
org.apache.hadoop.dfs.FSDirectory.unprotectedSetPermission(FSDirectory.java:422)
    [junit]     at 
org.apache.hadoop.dfs.FSDirectory.setPermission(FSDirectory.java:414)
    [junit]     at 
org.apache.hadoop.dfs.FSNamesystem.setPermission(FSNamesystem.java:754)
    [junit]     at 
org.apache.hadoop.dfs.NameNode.setPermission(NameNode.java:285)
    [junit]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    [junit]     at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    [junit]     at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    [junit]     at java.lang.reflect.Method.invoke(Method.java:585)
    [junit]     at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:446)
    [junit]     at org.apache.hadoop.ipc.Server$Handler.run(Server.java:896)
    [junit] 2008-04-10 12:23:54,694 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 5 on 41099, 
ugi=null
    [junit] Shutting down the Mini HDFS Cluster
    [junit] Shutting down DataNode 2
    [junit] 2008-04-10 12:23:46,643 WARN  dfs.DataNode 
(DataNode.java:offerService(704)) - java.net.SocketTimeoutException: timed out 
waiting for rpc response
    [junit]     at org.apache.hadoop.ipc.Client.call(Client.java:559)
    [junit]     at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:212)
    [junit]     at org.apache.hadoop.dfs.$Proxy1.sendHeartbeat(Unknown Source)
    [junit]     at 
org.apache.hadoop.dfs.DataNode.offerService(DataNode.java:606)
    [junit]     at org.apache.hadoop.dfs.DataNode.run(DataNode.java:2654)
    [junit]     at java.lang.Thread.run(Thread.java:595)
    [junit] 
    [junit] 2008-04-10 12:23:54,697 INFO  util.ThreadedServer 
(ThreadedServer.java:run(656)) - Stopping Acceptor 
ServerSocket[addr=localhost/127.0.0.1,port=0,localport=41108]
    [junit] 2008-04-10 12:23:44,893 WARN  dfs.DataNode 
(DataNode.java:offerService(704)) - java.net.SocketTimeoutException: timed out 
waiting for rpc response
    [junit]     at org.apache.hadoop.ipc.Client.call(Client.java:559)
    [junit]     at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:212)
    [junit]     at org.apache.hadoop.dfs.$Proxy1.sendHeartbeat(Unknown Source)
    [junit]     at 
org.apache.hadoop.dfs.DataNode.offerService(DataNode.java:606)
    [junit]     at org.apache.hadoop.dfs.DataNode.run(DataNode.java:2654)
    [junit]     at java.lang.Thread.run(Thread.java:595)
    [junit] 
    [junit] 2008-04-10 12:23:44,863 WARN  dfs.DataNode 
(DataNode.java:offerService(704)) - java.net.SocketTimeoutException: timed out 
waiting for rpc response
    [junit]     at org.apache.hadoop.ipc.Client.call(Client.java:559)
    [junit]     at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:212)
    [junit]     at org.apache.hadoop.dfs.$Proxy1.sendHeartbeat(Unknown Source)
    [junit]     at 
org.apache.hadoop.dfs.DataNode.offerService(DataNode.java:606)
    [junit]     at org.apache.hadoop.dfs.DataNode.run(DataNode.java:2654)
    [junit]     at java.lang.Thread.run(Thread.java:595)
    [junit] 
    [junit] 2008-04-10 12:22:46,635 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:44,885 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:54,699 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:54,700 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 41099, 
ugi=null
    [junit] 2008-04-10 12:22:44,856 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 7 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:54,701 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 7 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:54,726 INFO  http.SocketListener 
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:41108
    [junit] 2008-04-10 12:23:54,729 INFO  util.Container 
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
    [junit] 2008-04-10 12:23:55,077 INFO  util.Container 
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
    [junit] 2008-04-10 12:23:55,161 INFO  util.Container 
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
    [junit] 2008-04-10 12:23:55,253 INFO  util.Container 
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
    [junit] 2008-04-10 12:23:55,254 INFO  util.Container 
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
    [junit] 2008-04-10 12:23:55,255 INFO  dfs.DataNode 
(DataNode.java:shutdown(492)) - Waiting for threadgroup to exit, active threads 
is 1
    [junit] 2008-04-10 12:23:55,336 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:55,341 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:55,347 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:55,348 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:55,349 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:55,350 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:55,351 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:55,352 DEBUG security.UserGroupInformation 
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 41099, 
ugi=null
    [junit] 2008-04-10 12:23:55,352 INFO  dfs.DataNode 
(DataNode.java:offerService(665)) - BlockReport of 0 blocks got processed in 2 
msecs
    [junit] 2008-04-10 12:23:55,573 INFO  dfs.DataBlockScanner 
(DataBlockScanner.java:run(561)) - Exiting DataBlockScanner thread.
    [junit] 2008-04-10 12:23:56,263 INFO  dfs.DataNode 
(DataNode.java:shutdown(492)) - Waiting for threadgroup to exit, active threads 
is 0
    [junit] 2008-04-10 12:23:56,264 INFO  dfs.DataNode 
(DataNode.java:run(2672)) - 127.0.0.1:41107:Finishing DataNode in: 
FSDataset{dirpath='/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data5/current,/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data6/current'}
    [junit] Shutting down DataNode 1
    [junit] 2008-04-10 12:23:56,267 INFO  http.SocketListener 
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:41106
    [junit] 2008-04-10 12:23:56,268 INFO  util.Container 
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
    [junit] 2008-04-10 12:23:56,384 INFO  util.Container 
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
    [junit] 2008-04-10 12:23:56,457 INFO  util.Container 
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
    [junit] 2008-04-10 12:23:56,527 INFO  util.Container 
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
    [junit] 2008-04-10 12:23:56,528 INFO  util.Container 
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
    [junit] 2008-04-10 12:23:56,528 INFO  dfs.DataNode 
(DataNode.java:shutdown(492)) - Waiting for threadgroup to exit, active threads 
is 1
    [junit] 2008-04-10 12:23:56,529 INFO  dfs.DataNode 
(DataNode.java:run(2672)) - 127.0.0.1:41105:Finishing DataNode in: 
FSDataset{dirpath='/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data3/current,/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data4/current'}
    [junit] 2008-04-10 12:23:56,529 INFO  dfs.DataBlockScanner 
(DataBlockScanner.java:run(561)) - Exiting DataBlockScanner thread.
    [junit] Shutting down DataNode 0
    [junit] 2008-04-10 12:23:56,530 INFO  http.SocketListener 
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:41104
    [junit] 2008-04-10 12:23:56,530 INFO  util.Container 
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
    [junit] 2008-04-10 12:23:56,603 INFO  util.Container 
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
    [junit] 2008-04-10 12:23:56,669 INFO  util.Container 
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
    [junit] 2008-04-10 12:23:56,735 INFO  util.Container 
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
    [junit] 2008-04-10 12:23:56,736 INFO  util.Container 
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
    [junit] 2008-04-10 12:23:56,736 INFO  dfs.DataNode 
(DataNode.java:shutdown(492)) - Waiting for threadgroup to exit, active threads 
is 1
    [junit] 2008-04-10 12:23:56,737 INFO  dfs.DataBlockScanner 
(DataBlockScanner.java:run(561)) - Exiting DataBlockScanner thread.
    [junit] 2008-04-10 12:23:56,737 INFO  dfs.DataNode 
(DataNode.java:run(2672)) - 127.0.0.1:41103:Finishing DataNode in: 
FSDataset{dirpath='/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data1/current,/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build/test/data/dfs/data/data2/current'}
    [junit] 2008-04-10 12:23:56,738 INFO  util.ThreadedServer 
(ThreadedServer.java:run(656)) - Stopping Acceptor 
ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=41100]
    [junit] 2008-04-10 12:23:56,738 INFO  http.SocketListener 
(SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:41100
    [junit] 2008-04-10 12:23:56,739 INFO  util.Container 
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
    [junit] 2008-04-10 12:23:56,806 INFO  util.Container 
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
    [junit] 2008-04-10 12:23:56,869 INFO  util.Container 
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
    [junit] 2008-04-10 12:23:56,932 INFO  util.Container 
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
    [junit] 2008-04-10 12:23:56,932 INFO  util.Container 
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
    [junit] 2008-04-10 12:23:56,933 WARN  fs.FSNamesystem 
(FSNamesystem.java:run(2253)) - ReplicationMonitor thread received 
InterruptedException.java.lang.InterruptedException: sleep interrupted
    [junit] 2008-04-10 12:23:56,933 INFO  fs.FSNamesystem 
(FSEditLog.java:printStatistics(846)) - Number of transactions: 0 Total time 
for transactions(ms): 0 Number of syncs: 0 SyncTimes(ms): 0 0 
    [junit] 2008-04-10 12:23:56,933 ERROR fs.FSNamesystem 
(FSNamesystem.java:run(1940)) - java.lang.InterruptedException
    [junit]     at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:1815)
    [junit]     at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1850)
    [junit]     at 
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)
    [junit]     at 
org.apache.hadoop.dfs.FSNamesystem$ResolutionMonitor.run(FSNamesystem.java:1917)
    [junit]     at java.lang.Thread.run(Thread.java:595)
    [junit] 
    [junit] 2008-04-10 12:23:56,933 INFO  ipc.Server (Server.java:stop(1001)) - 
Stopping server on 41099
    [junit] 2008-04-10 12:23:56,934 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 0 on 41099: exiting
    [junit] 2008-04-10 12:23:56,934 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 1 on 41099: exiting
    [junit] 2008-04-10 12:23:56,934 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 6 on 41099: exiting
    [junit] 2008-04-10 12:23:56,935 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 3 on 41099: exiting
    [junit] 2008-04-10 12:23:56,934 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 8 on 41099: exiting
    [junit] 2008-04-10 12:23:56,934 INFO  ipc.Server (Server.java:run(329)) - 
Stopping IPC Server listener on 41099
    [junit] 2008-04-10 12:23:56,937 INFO  ipc.Server (Server.java:run(492)) - 
Stopping IPC Server Responder
    [junit] 2008-04-10 12:23:56,937 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 9 on 41099: exiting
    [junit] 2008-04-10 12:23:56,938 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 7 on 41099: exiting
    [junit] 2008-04-10 12:23:56,938 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 5 on 41099: exiting
    [junit] 2008-04-10 12:23:56,939 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 4 on 41099: exiting
    [junit] 2008-04-10 12:23:56,939 INFO  ipc.Server (Server.java:run(928)) - 
IPC Server handler 2 on 41099: exiting
    [junit] Tests run: 2, Failures: 0, Errors: 1, Time elapsed: 91.646 sec
    [junit] Test org.apache.hadoop.security.TestPermission FAILED
    [junit] Running org.apache.hadoop.security.TestUnixUserGroupInformation
    [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.408 sec
    [junit] Running org.apache.hadoop.util.TestGenericsUtil
    [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.146 sec
    [junit] Running org.apache.hadoop.util.TestIndexedSort
    [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.594 sec
    [junit] Running org.apache.hadoop.util.TestReflectionUtils
    [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.632 sec
    [junit] Running org.apache.hadoop.util.TestShell
    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.253 sec
    [junit] Running org.apache.hadoop.util.TestStringUtils
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.108 sec

BUILD FAILED
/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build.xml:589:
 Tests failed!

Total time: 63 minutes 59 seconds
Recording fingerprints
Publishing Javadoc
Recording test results
Updating HADOOP-3069
Updating HADOOP-3175
Updating HADOOP-3220
Updating HADOOP-3208
Updating HADOOP-3143

Reply via email to