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