See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/420/changes
Changes:
[dhruba] HADOOP-2883. Write failures and data corruptions on HDFS files.
The write timeout is back to what it was on 0.15 release. Also, the
datnodes flushes the block file buffered output stream before
sending a positive ack for the packet back to the client. (dhruba)
[nigel] HADOOP-2861. INCOMPATIBLE CHANGE. Improve the user interface for the
HOD commands. Command line structure has changed. Contributed by Hemanth
Yamijala.
[nigel] HADOOP-2861. INCOMPATIBLE CHANGE. Improve the user interface for the
HOD commands. Command line structure has changed. Contributed by Hemanth
Yamijala.
------------------------------------------
[...truncated 96369 lines...]
[junit] 2008-03-05 15:59:41,184 INFO net.NetworkTopology
(NetworkTopology.java:add(321)) - Adding a new node:
/default-rack/127.0.0.1:48964
[junit] 2008-03-05 15:59:41,259 INFO dfs.DataNode
(FSDataset.java:registerMBean(956)) - Registered FSDatasetStatusMBean
[junit] 2008-03-05 15:59:41,260 INFO dfs.DataNode
(DataNode.java:startDataNode(259)) - Opened server at 48966
[junit] 2008-03-05 15:59:41,261 INFO dfs.DataNode
(DataNode.java:startDataNode(281)) - Balancing bandwith is 1048576 bytes/s
[junit] 2008-03-05 15:59:41,266 INFO http.HttpServer
(HttpServer.java:doStart(729)) - Version Jetty/5.1.4
[junit] 2008-03-05 15:59:41,357 INFO util.Container
(Container.java:start(74)) - Started [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:41,359 INFO util.Container
(Container.java:start(74)) - Started WebApplicationContext[/,/]
[junit] 2008-03-05 15:59:41,360 INFO util.Container
(Container.java:start(74)) - Started HttpContext[/logs,/logs]
[junit] 2008-03-05 15:59:41,360 INFO util.Container
(Container.java:start(74)) - Started HttpContext[/static,/static]
[junit] 2008-03-05 15:59:41,363 INFO http.SocketListener
(SocketListener.java:start(204)) - Started SocketListener on 127.0.0.1:48967
[junit] 2008-03-05 15:59:41,364 INFO util.Container
(Container.java:start(74)) - Started [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:41,365 INFO jvm.JvmMetrics
(JvmMetrics.java:init(62)) - Cannot initialize JVM Metrics with
processName=DataNode, sessionId=null - already initialized
[junit] 2008-03-05 15:59:41,368 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 6 on 48957,
ugi=null
[junit] 2008-03-05 15:59:41,369 INFO dfs.StateChange
(FSNamesystem.java:registerDatanode(1979)) - BLOCK*
NameSystem.registerDatanode: node registration from 127.0.0.1:48966 storage
DS-1553970926-140.211.11.106-48966-1204732781368
[junit] 2008-03-05 15:59:41,369 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 6 on 48957,
ugi=null
[junit] 2008-03-05 15:59:41,405 INFO dfs.DataNode
(DataNode.java:register(444)) - New storage id
DS-1553970926-140.211.11.106-48966-1204732781368 is assigned to data-node
127.0.0.1:48966
[junit] 2008-03-05 15:59:41,409 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 2 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:41,410 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 2 on 48957,
ugi=null
[junit] 2008-03-05 15:59:41,410 INFO dfs.DataNode
(DataNode.java:run(2593)) - 127.0.0.1:48966In 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-03-05 15:59:41,411 INFO dfs.DataNode
(DataNode.java:offerService(562)) - using BLOCKREPORT_INTERVAL of 3555687msec
Initial delay: 0msec
[junit] 2008-03-05 15:59:41,452 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 0 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:41,454 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:41,456 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 0 on 48957,
ugi=null
[junit] 2008-03-05 15:59:41,651 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 7 on 48957,
ugi=null
[junit] 2008-03-05 15:59:41,654 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 7 on 48957,
ugi=null
[junit] 2008-03-05 15:59:41,656 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 5 on 48957,
ugi=null
[junit] 2008-03-05 15:59:41,657 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 5 on 48957,
ugi=null
[junit] 2008-03-05 15:59:41,657 INFO dfs.DataNode
(DataNode.java:offerService(646)) - BlockReport of 0 blocks got processed in 2
msecs
[junit] 2008-03-05 15:59:41,964 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 3 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:41,965 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:41,965 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 3 on 48957,
ugi=null
[junit] 2008-03-05 15:59:42,474 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 1 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:42,475 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:42,476 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 1 on 48957,
ugi=null
[junit] 2008-03-05 15:59:42,984 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 9 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:42,984 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:42,984 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 9 on 48957,
ugi=null
[junit] 2008-03-05 15:59:43,194 INFO net.NetworkTopology
(NetworkTopology.java:add(321)) - Adding a new node:
/default-rack/127.0.0.1:48966
[junit] 2008-03-05 15:59:43,494 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 4 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:43,494 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:43,494 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 4 on 48957,
ugi=null
[junit] 2008-03-05 15:59:43,566 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 8 on 48957,
ugi=null
[junit] 2008-03-05 15:59:43,566 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 8 on 48957,
ugi=null
[junit] 2008-03-05 15:59:43,567 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 6 on 48957,
ugi=null
[junit] 2008-03-05 15:59:43,568 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 6 on 48957,
ugi=null
[junit] 2008-03-05 15:59:43,569 INFO dfs.DataNode
(DataNode.java:offerService(646)) - BlockReport of 0 blocks got processed in 2
msecs
[junit] 2008-03-05 15:59:44,014 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 2 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,015 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 2 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,017 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 0 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,017 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 0 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,017 INFO dfs.DataNode
(DataNode.java:offerService(646)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2008-03-05 15:59:44,414 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 7 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,414 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 7 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,417 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 5 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,417 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 5 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,417 INFO dfs.DataNode
(DataNode.java:offerService(646)) - BlockReport of 0 blocks got processed in 1
msecs
[junit] 2008-03-05 15:59:44,483 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:44,485 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 3 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:44,486 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 3 on 48957,
ugi=null
[junit] 2008-03-05 15:59:44,486 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 1 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:44,487 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:44,487 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 1 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,493 WARN fs.FileSystem
(FileSystem.java:fixName(153)) - "localhost:48957" is a deprecated filesystem
name. Use "hdfs://localhost:48957/" instead.
[junit] 2008-03-05 15:59:45,495 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 9 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,495 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,522 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 9 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,524 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 4 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,525 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,525 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,548 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 4 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,550 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 8 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,551 INFO dfs.StateChange
(FSNamesystem.java:allocateBlock(1312)) - BLOCK* NameSystem.allocateBlock:
/data/file1. blk_2420046476205940188
[junit] 2008-03-05 15:59:45,551 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 8 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,553 INFO dfs.DataNode
(DataNode.java:writeBlock(1057)) - Receiving block blk_2420046476205940188 src:
/127.0.0.1:48971 dest: /127.0.0.1:48966
[junit] 2008-03-05 15:59:45,556 INFO dfs.DataNode
(DataNode.java:writeBlock(1057)) - Receiving block blk_2420046476205940188 src:
/127.0.0.1:48972 dest: /127.0.0.1:48962
[junit] 2008-03-05 15:59:45,563 INFO dfs.DataNode
(DataNode.java:writeBlock(1057)) - Receiving block blk_2420046476205940188 src:
/127.0.0.1:48973 dest: /127.0.0.1:48964
[junit] 2008-03-05 15:59:45,564 INFO dfs.DataNode
(DataNode.java:writeBlock(1150)) - Datanode 0 forwarding connect ack to
upstream firstbadlink is
[junit] 2008-03-05 15:59:45,565 INFO dfs.DataNode
(DataNode.java:writeBlock(1127)) - Datanode 1 got response for connect ack
from downstream datanode with firstbadlink as
[junit] 2008-03-05 15:59:45,565 INFO dfs.DataNode
(DataNode.java:writeBlock(1150)) - Datanode 1 forwarding connect ack to
upstream firstbadlink is
[junit] 2008-03-05 15:59:45,565 INFO dfs.DataNode
(DataNode.java:writeBlock(1127)) - Datanode 2 got response for connect ack
from downstream datanode with firstbadlink as
[junit] 2008-03-05 15:59:45,566 INFO dfs.DataNode
(DataNode.java:writeBlock(1150)) - Datanode 2 forwarding connect ack to
upstream firstbadlink is
[junit] 2008-03-05 15:59:45,568 INFO dfs.DataNode
(DataNode.java:lastDataNodeRun(1896)) - Received block blk_2420046476205940188
of size 100 from /127.0.0.1
[junit] 2008-03-05 15:59:45,568 INFO dfs.DataNode
(DataNode.java:lastDataNodeRun(1919)) - PacketResponder 0 for block
blk_2420046476205940188 terminating
[junit] 2008-03-05 15:59:45,569 INFO dfs.DataNode
(DataNode.java:run(1986)) - Received block blk_2420046476205940188 of size 100
from /127.0.0.1
[junit] 2008-03-05 15:59:45,570 INFO dfs.DataNode
(DataNode.java:run(2050)) - PacketResponder 1 for block blk_2420046476205940188
terminating
[junit] 2008-03-05 15:59:45,568 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 6 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,570 INFO dfs.DataNode
(DataNode.java:run(1986)) - Received block blk_2420046476205940188 of size 100
from /127.0.0.1
[junit] 2008-03-05 15:59:45,571 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 2 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,571 INFO dfs.DataNode
(DataNode.java:run(2050)) - PacketResponder 2 for block blk_2420046476205940188
terminating
[junit] 2008-03-05 15:59:45,572 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 0 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,571 INFO dfs.StateChange
(FSNamesystem.java:addStoredBlock(2599)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:48964 is added to blk_2420046476205940188 size 100
[junit] 2008-03-05 15:59:45,573 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 6 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,573 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 6 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,574 INFO dfs.StateChange
(FSNamesystem.java:addStoredBlock(2599)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:48966 is added to blk_2420046476205940188 size 100
[junit] 2008-03-05 15:59:45,574 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 0 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,576 INFO dfs.StateChange
(FSNamesystem.java:addStoredBlock(2599)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:48962 is added to blk_2420046476205940188 size 100
[junit] 2008-03-05 15:59:45,576 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 2 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,597 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 6 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,598 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 5 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,599 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,622 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 5 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,632 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 3 on 48957,
ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,633 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-03-05 15:59:45,637 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 3 on 48957,
ugi=null
[junit] 2008-03-05 15:59:45,657 INFO dfs.DataNode
(DataNode.java:readBlock(1024)) - 127.0.0.1:48962 Served block
blk_2420046476205940188 to /127.0.0.1
[junit] 2008-03-05 15:59:46,543 WARN fs.FileSystem
(FileSystem.java:fixName(153)) - "localhost:48957" is a deprecated filesystem
name. Use "hdfs://localhost:48957/" instead.
[junit] 2008-03-05 15:59:46,546 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 1 on 48957,
ugi=Who,group1,group2
[junit] 2008-03-05 15:59:46,546 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 1 on 48957,
ugi=null
[junit] 2008-03-05 15:59:46,547 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 9 on 48957,
ugi=Who,group1,group2
[junit] 2008-03-05 15:59:46,548 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=Who,group1,group2
[junit] 2008-03-05 15:59:46,548 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(87)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=WRITE, parentAccess=null, access=null,
subAccess=null
[junit] 2008-03-05 15:59:46,564 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 4 on 48957,
ugi=null
[junit] 2008-03-05 15:59:46,565 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 4 on 48957,
ugi=null
[junit] 2008-03-05 15:59:46,568 INFO ipc.Server (Server.java:run(901)) -
IPC Server handler 9 on 48957, call mkdirs(/data/web2, rwxr-xr-x) from
127.0.0.1:48976: error: org.apache.hadoop.fs.permission.AccessControlException:
Permission denied: user=Who, access=WRITE,
inode="data":hudson:supergroup:rwxr-xr-x
[junit] org.apache.hadoop.fs.permission.AccessControlException: Permission
denied: user=Who, access=WRITE, inode="data":hudson:supergroup:rwxr-xr-x
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:173)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:154)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.checkPermission(PermissionChecker.java:102)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkPermission(FSNamesystem.java:4130)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkAncestorAccess(FSNamesystem.java:4100)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.mkdirsInternal(FSNamesystem.java:1588)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.mkdirs(FSNamesystem.java:1571)
[junit] at org.apache.hadoop.dfs.NameNode.mkdirs(NameNode.java:424)
[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:409)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:899)
[junit] 2008-03-05 15:59:46,570 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 9 on 48957,
ugi=null
[junit] 2008-03-05 15:59:46,578 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 8 on 48957,
ugi=Who,group1,group2
[junit] 2008-03-05 15:59:46,579 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=Who,group1,group2
[junit] 2008-03-05 15:59:46,579 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(87)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=null, parentAccess=null, access=null,
subAccess=null
[junit] 2008-03-05 15:59:46,580 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=Who,group1,group2
[junit] 2008-03-05 15:59:46,580 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(87)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=WRITE, parentAccess=null, access=null,
subAccess=null
[junit] 2008-03-05 15:59:46,581 INFO ipc.Server (Server.java:run(901)) -
IPC Server handler 8 on 48957, call create(/data/file2, rwxr-xr-x,
DFSClient_538887968, true, 3, 67108864) from 127.0.0.1:48976: error:
org.apache.hadoop.fs.permission.AccessControlException: Permission denied:
user=Who, access=WRITE, inode="data":hudson:supergroup:rwxr-xr-x
[junit] org.apache.hadoop.fs.permission.AccessControlException: Permission
denied: user=Who, access=WRITE, inode="data":hudson:supergroup:rwxr-xr-x
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:173)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:154)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.checkPermission(PermissionChecker.java:102)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkPermission(FSNamesystem.java:4130)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkAncestorAccess(FSNamesystem.java:4100)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.startFileInternal(FSNamesystem.java:980)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.startFile(FSNamesystem.java:955)
[junit] at org.apache.hadoop.dfs.NameNode.create(NameNode.java:282)
[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:409)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:899)
[junit] 2008-03-05 15:59:46,582 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 8 on 48957,
ugi=null
[junit] 2008-03-05 15:59:46,583 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 7 on 48957,
ugi=Who,group1,group2
[junit] 2008-03-05 15:59:46,584 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=Who,group1,group2
[junit] 2008-03-05 15:59:46,584 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(87)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=null, parentAccess=null, access=READ,
subAccess=null
[junit] 2008-03-05 15:59:46,585 INFO ipc.Server (Server.java:run(901)) -
IPC Server handler 7 on 48957, call open(/data/file1, 0, 671088640) from
127.0.0.1:48976: error: org.apache.hadoop.fs.permission.AccessControlException:
Permission denied: user=Who, access=READ,
inode="file1":hudson:supergroup:rw-------
[junit] org.apache.hadoop.fs.permission.AccessControlException: Permission
denied: user=Who, access=READ, inode="file1":hudson:supergroup:rw-------
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:173)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.checkPermission(PermissionChecker.java:108)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkPermission(FSNamesystem.java:4130)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkPathAccess(FSNamesystem.java:4090)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.getBlockLocations(FSNamesystem.java:772)
[junit] at
org.apache.hadoop.dfs.NameNode.getBlockLocations(NameNode.java:255)
[junit] at org.apache.hadoop.dfs.NameNode.open(NameNode.java:242)
[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:409)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:899)
[junit] 2008-03-05 15:59:46,586 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 7 on 48957,
ugi=null
[junit] 2008-03-05 15:59:47,014 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 0 on 48957,
ugi=null
[junit] 2008-03-05 15:59:47,015 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 0 on 48957,
ugi=null
[junit] 2008-03-05 15:59:47,414 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 2 on 48957,
ugi=null
[junit] 2008-03-05 15:59:47,416 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(40)) - IPC Server handler 2 on 48957,
ugi=null
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 2
[junit] 2008-03-05 15:59:47,555 INFO http.SocketListener
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:48967
[junit] 2008-03-05 15:59:47,556 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:47,744 INFO util.Container
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
[junit] 2008-03-05 15:59:47,817 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
[junit] 2008-03-05 15:59:47,900 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
[junit] 2008-03-05 15:59:47,901 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:47,902 INFO dfs.DataNode
(DataNode.java:shutdown(474)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2008-03-05 15:59:47,903 INFO dfs.DataNode
(DataNode.java:run(2624)) - 127.0.0.1:48966: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-03-05 15:59:47,903 INFO dfs.DataBlockScanner
(DataBlockScanner.java:run(561)) - Exiting DataBlockScanner thread.
[junit] 2008-03-05 15:59:47,904 INFO http.SocketListener
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:48965
[junit] 2008-03-05 15:59:47,905 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:47,974 INFO util.Container
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
[junit] 2008-03-05 15:59:48,042 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
[junit] 2008-03-05 15:59:48,110 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
[junit] 2008-03-05 15:59:48,111 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:48,111 INFO dfs.DataNode
(DataNode.java:shutdown(474)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2008-03-05 15:59:48,123 INFO dfs.DataBlockScanner
(DataBlockScanner.java:run(561)) - Exiting DataBlockScanner thread.
[junit] 2008-03-05 15:59:49,113 INFO dfs.DataNode
(DataNode.java:shutdown(474)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2008-03-05 15:59:49,114 INFO dfs.DataNode
(DataNode.java:run(2624)) - 127.0.0.1:48964: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] Shutting down DataNode 0
[junit] 2008-03-05 15:59:49,114 INFO util.ThreadedServer
(ThreadedServer.java:run(656)) - Stopping Acceptor
ServerSocket[addr=localhost/127.0.0.1,port=0,localport=48963]
[junit] 2008-03-05 15:59:49,115 INFO http.SocketListener
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:48963
[junit] 2008-03-05 15:59:49,115 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:49,184 INFO util.Container
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
[junit] 2008-03-05 15:59:49,249 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
[junit] 2008-03-05 15:59:49,313 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
[junit] 2008-03-05 15:59:49,314 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:49,315 INFO dfs.DataNode
(DataNode.java:shutdown(474)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2008-03-05 15:59:49,315 INFO dfs.DataNode
(DataNode.java:run(2624)) - 127.0.0.1:48962: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-03-05 15:59:49,315 INFO dfs.DataBlockScanner
(DataBlockScanner.java:run(561)) - Exiting DataBlockScanner thread.
[junit] 2008-03-05 15:59:49,317 INFO http.SocketListener
(SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:48958
[junit] 2008-03-05 15:59:49,317 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:49,383 INFO util.Container
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
[junit] 2008-03-05 15:59:49,446 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
[junit] 2008-03-05 15:59:49,507 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
[junit] 2008-03-05 15:59:49,507 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-03-05 15:59:49,508 ERROR fs.FSNamesystem
(FSNamesystem.java:run(1901)) - java.lang.InterruptedException: sleep
interrupted
[junit] at java.lang.Thread.sleep(Native Method)
[junit] at
org.apache.hadoop.dfs.FSNamesystem$ResolutionMonitor.run(FSNamesystem.java:1879)
[junit] at java.lang.Thread.run(Thread.java:595)
[junit]
[junit] 2008-03-05 15:59:49,508 INFO fs.FSNamesystem
(FSEditLog.java:printStatistics(845)) - Number of transactions: 6 Total time
for transactions(ms): 0 Number of syncs: 4 SyncTimes(ms): 53 37
[junit] 2008-03-05 15:59:49,509 INFO ipc.Server (Server.java:stop(1004)) -
Stopping server on 48957
[junit] 2008-03-05 15:59:49,509 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 0 on 48957: exiting
[junit] 2008-03-05 15:59:49,510 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 2 on 48957: exiting
[junit] 2008-03-05 15:59:49,510 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 9 on 48957: exiting
[junit] 2008-03-05 15:59:49,510 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 6 on 48957: exiting
[junit] 2008-03-05 15:59:49,511 INFO ipc.Server (Server.java:run(495)) -
Stopping IPC Server Responder
[junit] 2008-03-05 15:59:49,512 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 5 on 48957: exiting
[junit] 2008-03-05 15:59:49,512 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 7 on 48957: exiting
[junit] 2008-03-05 15:59:49,512 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 8 on 48957: exiting
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 22.921 sec
[junit] 2008-03-05 15:59:49,510 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 1 on 48957: exiting
[junit] 2008-03-05 15:59:49,510 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 4 on 48957: exiting
[junit] 2008-03-05 15:59:49,509 INFO ipc.Server (Server.java:run(931)) -
IPC Server handler 3 on 48957: exiting
[junit] Running org.apache.hadoop.security.TestUnixUserGroupInformation
[junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.464 sec
[junit] Running org.apache.hadoop.util.TestReflectionUtils
[junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.667 sec
[junit] Running org.apache.hadoop.util.TestShell
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.378 sec
BUILD FAILED
/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build.xml:570:
Tests failed!
Total time: 106 minutes 52 seconds
Recording fingerprints
Publishing Javadoc
Recording test results
Updating HADOOP-2861
Updating HADOOP-2883
