See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/501/changes
------------------------------------------
[...truncated 120117 lines...]
[junit]
[junit] 2008-05-24 12:31:15,385 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,386 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,387 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,409 INFO FSNamesystem.audit
(FSNamesystem.java:mkdirs(1532)) - ugi=hudson,hudson ip=/127.0.0.1
cmd=mkdirs path=/data/child1 perm=hudson:supergroup:rwxr-xr-x
[junit] 2008-05-24 12:31:15,410 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,411 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,412 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,442 INFO FSNamesystem.audit
(FSNamesystem.java:startFile(894)) - ugi=hudson,hudson ip=/127.0.0.1
cmd=create path=/data/file1 perm=hudson:supergroup:rw-r--r--
[junit] 2008-05-24 12:31:15,442 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,444 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 7 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,446 INFO dfs.StateChange
(FSNamesystem.java:allocateBlock(1229)) - BLOCK* NameSystem.allocateBlock:
/data/file1. blk_-7462181610345998126_1001
[junit] 2008-05-24 12:31:15,446 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 7 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,449 INFO dfs.DataNode
(DataNode.java:writeBlock(1136)) - Receiving block
blk_-7462181610345998126_1001 src: /127.0.0.1:38442 dest: /127.0.0.1:38436
[junit] 2008-05-24 12:31:15,451 INFO dfs.DataNode
(DataNode.java:writeBlock(1136)) - Receiving block
blk_-7462181610345998126_1001 src: /127.0.0.1:38443 dest: /127.0.0.1:38439
[junit] 2008-05-24 12:31:15,521 INFO dfs.DataNode
(DataNode.java:writeBlock(1136)) - Receiving block
blk_-7462181610345998126_1001 src: /127.0.0.1:38444 dest: /127.0.0.1:38433
[junit] 2008-05-24 12:31:15,525 INFO dfs.DataNode
(DataNode.java:lastDataNodeRun(2070)) - Received block
blk_-7462181610345998126_1001 of size 100 from /127.0.0.1
[junit] 2008-05-24 12:31:15,526 INFO dfs.DataNode
(DataNode.java:lastDataNodeRun(2088)) - PacketResponder 0 for block
blk_-7462181610345998126_1001 terminating
[junit] 2008-05-24 12:31:15,527 INFO dfs.DataNode
(DataNode.java:run(2175)) - Received block blk_-7462181610345998126_1001 of
size 100 from /127.0.0.1
[junit] 2008-05-24 12:31:15,527 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 4 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,527 INFO dfs.DataNode
(DataNode.java:run(2233)) - PacketResponder 1 for block
blk_-7462181610345998126_1001 terminating
[junit] 2008-05-24 12:31:15,528 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,527 INFO dfs.StateChange
(FSNamesystem.java:addStoredBlock(2668)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:38433 is added to blk_-7462181610345998126_1001
size 100
[junit] 2008-05-24 12:31:15,529 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 4 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,529 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 1 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,528 INFO dfs.DataNode
(DataNode.java:run(2175)) - Received block blk_-7462181610345998126_1001 of
size 100 from /127.0.0.1
[junit] 2008-05-24 12:31:15,530 INFO dfs.DataNode
(DataNode.java:run(2233)) - PacketResponder 2 for block
blk_-7462181610345998126_1001 terminating
[junit] 2008-05-24 12:31:15,529 INFO dfs.StateChange
(FSNamesystem.java:addStoredBlock(2668)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:38439 is added to blk_-7462181610345998126_1001
size 100
[junit] 2008-05-24 12:31:15,531 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,531 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 5 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,533 INFO dfs.StateChange
(FSNamesystem.java:addStoredBlock(2668)) - BLOCK* NameSystem.addStoredBlock:
blockMap updated: 127.0.0.1:38436 is added to blk_-7462181610345998126_1001
size 100
[junit] 2008-05-24 12:31:15,533 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 1 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,534 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,535 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,536 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,536 INFO dfs.DataNode
(DataNode.java:offerService(714)) - BlockReport of 1 blocks got processed in 3
msecs
[junit] 2008-05-24 12:31:15,536 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,537 INFO dfs.DataNode
(DataNode.java:offerService(714)) - BlockReport of 1 blocks got processed in 3
msecs
[junit] 2008-05-24 12:31:15,562 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 5 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,563 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,563 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,584 INFO FSNamesystem.audit
(FSNamesystem.java:setPermission(640)) - ugi=hudson,hudson ip=/127.0.0.1
cmd=setPermission path=/data/file1 perm=hudson:supergroup:rw-------
[junit] 2008-05-24 12:31:15,584 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,593 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,594 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,597 INFO FSNamesystem.audit
(FSNamesystem.java:getBlockLocations(714)) - ugi=hudson,hudson
ip=/127.0.0.1 cmd=open path=/data/file1 perm=null
[junit] 2008-05-24 12:31:15,597 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,615 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 38429,
ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,616 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,616 INFO dfs.DataNode
(DataNode.java:readBlock(1102)) - DatanodeRegistration(127.0.0.1:38433,
storageID=DS-378705661-140.211.11.106-38433-1211632271646, infoPort=38434,
ipcPort=38435) Served block blk_-7462181610345998126_1001 to /127.0.0.1
[junit] 2008-05-24 12:31:15,617 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 7 on 38429,
ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,617 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,618 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=null, parentAccess=null, access=null,
subAccess=null
[junit] 2008-05-24 12:31:15,618 INFO FSNamesystem.audit
(FSNamesystem.java:mkdirs(1532)) - ugi=user626914502,group1,group2
ip=/127.0.0.1 cmd=mkdirs path=/data/child1
perm=hudson:supergroup:rwxr-xr-x
[junit] 2008-05-24 12:31:15,619 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 7 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,619 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 4 on 38429,
ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,620 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,620 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=null, parentAccess=null, access=null,
subAccess=null
[junit] 2008-05-24 12:31:15,620 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,621 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=WRITE, parentAccess=null, access=null,
subAccess=null
[junit] 2008-05-24 12:31:15,627 INFO ipc.Server (Server.java:run(869)) -
IPC Server handler 4 on 38429, call mkdirs(/data/child2, rwxr-xr-x) from
127.0.0.1:38446: error: org.apache.hadoop.fs.permission.AccessControlException:
Permission denied: user=user626914502, access=WRITE,
inode="data":hudson:supergroup:rwxr-xr-x
[junit] org.apache.hadoop.fs.permission.AccessControlException: Permission
denied: user=user626914502, access=WRITE,
inode="data":hudson:supergroup:rwxr-xr-x
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:175)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:156)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.checkPermission(PermissionChecker.java:104)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkPermission(FSNamesystem.java:4058)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkAncestorAccess(FSNamesystem.java:4028)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.mkdirsInternal(FSNamesystem.java:1561)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.mkdirs(FSNamesystem.java:1528)
[junit] at org.apache.hadoop.dfs.NameNode.mkdirs(NameNode.java:412)
[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:452)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:867)
[junit] 2008-05-24 12:31:15,628 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 4 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,630 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,630 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 2 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,631 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 1 on 38429,
ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,631 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,631 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=WRITE, parentAccess=null, access=null,
subAccess=null
[junit] 2008-05-24 12:31:15,632 INFO ipc.Server (Server.java:run(869)) -
IPC Server handler 1 on 38429, call create(/data/file2, rwxr-xr-x,
DFSClient_329816604, true, 3, 67108864) from 127.0.0.1:38446: error:
org.apache.hadoop.fs.permission.AccessControlException: Permission denied:
user=user626914502, access=WRITE, inode="data":hudson:supergroup:rwxr-xr-x
[junit] org.apache.hadoop.fs.permission.AccessControlException: Permission
denied: user=user626914502, access=WRITE,
inode="data":hudson:supergroup:rwxr-xr-x
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:175)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:156)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.checkPermission(PermissionChecker.java:104)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkPermission(FSNamesystem.java:4058)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkAncestorAccess(FSNamesystem.java:4028)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.startFileInternal(FSNamesystem.java:922)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.startFile(FSNamesystem.java:889)
[junit] at org.apache.hadoop.dfs.NameNode.create(NameNode.java:284)
[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:452)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:867)
[junit] 2008-05-24 12:31:15,633 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 1 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,634 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 38429,
ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,635 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,635 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=null, parentAccess=null, access=READ,
subAccess=null
[junit] 2008-05-24 12:31:15,635 INFO ipc.Server (Server.java:run(869)) -
IPC Server handler 3 on 38429, call getBlockLocations(/data/file1, 0,
671088640) from 127.0.0.1:38446: error:
org.apache.hadoop.fs.permission.AccessControlException: Permission denied:
user=user626914502, access=READ, inode="file1":hudson:supergroup:rw-------
[junit] org.apache.hadoop.fs.permission.AccessControlException: Permission
denied: user=user626914502, access=READ,
inode="file1":hudson:supergroup:rw-------
[junit] at
org.apache.hadoop.dfs.PermissionChecker.check(PermissionChecker.java:175)
[junit] at
org.apache.hadoop.dfs.PermissionChecker.checkPermission(PermissionChecker.java:110)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkPermission(FSNamesystem.java:4058)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.checkPathAccess(FSNamesystem.java:4018)
[junit] at
org.apache.hadoop.dfs.FSNamesystem.getBlockLocations(FSNamesystem.java:684)
[junit] at
org.apache.hadoop.dfs.NameNode.getBlockLocations(NameNode.java:257)
[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:452)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:867)
[junit] 2008-05-24 12:31:15,636 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 3 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,637 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,638 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,659 INFO FSNamesystem.audit
(FSNamesystem.java:setPermission(640)) - ugi=hudson,hudson ip=/127.0.0.1
cmd=setPermission path=/data perm=hudson:supergroup:rwxr-xr-x
[junit] 2008-05-24 12:31:15,660 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 0 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,661 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 5 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,662 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,697 INFO FSNamesystem.audit
(FSNamesystem.java:setPermission(640)) - ugi=hudson,hudson ip=/127.0.0.1
cmd=setPermission path=/data/child1 perm=hudson:supergroup:rwxrwxrwx
[junit] 2008-05-24 12:31:15,697 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 5 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,698 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 38429,
ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,698 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=hudson,hudson
[junit] 2008-05-24 12:31:15,718 INFO FSNamesystem.audit
(FSNamesystem.java:setPermission(640)) - ugi=hudson,hudson ip=/127.0.0.1
cmd=setPermission path=/ perm=hudson:supergroup:rwxrwxrwx
[junit] 2008-05-24 12:31:15,718 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 6 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,719 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 38429,
ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,720 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,720 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=null, parentAccess=null, access=null,
subAccess=null
[junit] 2008-05-24 12:31:15,720 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,721 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=WRITE, parentAccess=null, access=null,
subAccess=null
[junit] 2008-05-24 12:31:15,739 INFO FSNamesystem.audit
(FSNamesystem.java:mkdirs(1532)) - ugi=user626914502,group1,group2
ip=/127.0.0.1 cmd=mkdirs path=/foo/bar
perm=user626914502:supergroup:rwxr-xr-x
[junit] 2008-05-24 12:31:15,739 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 9 on 38429,
ugi=null
[junit] 2008-05-24 12:31:15,740 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 38429,
ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,740 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,741 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=null, parentAccess=WRITE, access=null,
subAccess=null
[junit] 2008-05-24 12:31:15,741 DEBUG security.UserGroupInformation
(PermissionChecker.java:<init>(40)) - ugi=user626914502,group1,group2
[junit] 2008-05-24 12:31:15,741 DEBUG security.UserGroupInformation
(PermissionChecker.java:checkPermission(88)) - ACCESS CHECK: [EMAIL PROTECTED],
doCheckOwner=false, ancestorAccess=WRITE, parentAccess=null, access=null,
subAccess=null
[junit] 2008-05-24 12:31:15,765 DEBUG security.UserGroupInformation
(UserGroupInformation.java:setCurrentUGI(46)) - IPC Server handler 8 on 38429,
ugi=null
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 2
[junit] 2008-05-24 12:31:15,767 INFO http.SocketListener
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:38440
[junit] 2008-05-24 12:31:15,768 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-05-24 12:31:15,914 INFO util.Container
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
[junit] 2008-05-24 12:31:15,987 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
[junit] 2008-05-24 12:31:16,065 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
[junit] 2008-05-24 12:31:16,066 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-05-24 12:31:16,066 INFO ipc.Server (Server.java:stop(968)) -
Stopping server on 38441
[junit] 2008-05-24 12:31:16,066 INFO ipc.Server (Server.java:run(327)) -
Stopping IPC Server listener on 38441
[junit] 2008-05-24 12:31:16,067 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 2 on 38441: exiting
[junit] 2008-05-24 12:31:16,067 INFO dfs.DataNode (DataNode.java:run(956))
- DatanodeRegistration(127.0.0.1:38439,
storageID=DS-863423229-140.211.11.106-38439-1211632273243, infoPort=38440,
ipcPort=38441):Exiting DataXceiveServer due to
java.nio.channels.AsynchronousCloseException
[junit] 2008-05-24 12:31:16,068 INFO dfs.DataNode
(DataNode.java:shutdown(541)) - Waiting for threadgroup to exit, active threads
is 0
[junit] 2008-05-24 12:31:16,068 INFO ipc.Server (Server.java:run(499)) -
Stopping IPC Server Responder
[junit] 2008-05-24 12:31:16,067 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 1 on 38441: exiting
[junit] 2008-05-24 12:31:16,068 INFO dfs.DataBlockScanner
(DataBlockScanner.java:run(571)) - Exiting DataBlockScanner thread.
[junit] 2008-05-24 12:31:16,068 INFO dfs.DataNode
(DataNode.java:run(2868)) - DatanodeRegistration(127.0.0.1:38439,
storageID=DS-863423229-140.211.11.106-38439-1211632273243, infoPort=38440,
ipcPort=38441):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-05-24 12:31:16,067 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 0 on 38441: exiting
[junit] 2008-05-24 12:31:16,070 INFO util.ThreadedServer
(ThreadedServer.java:run(656)) - Stopping Acceptor
ServerSocket[addr=localhost/127.0.0.1,port=0,localport=38437]
[junit] 2008-05-24 12:31:16,070 INFO http.SocketListener
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:38437
[junit] 2008-05-24 12:31:16,072 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-05-24 12:31:16,143 INFO util.Container
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
[junit] 2008-05-24 12:31:16,215 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
[junit] 2008-05-24 12:31:16,284 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
[junit] 2008-05-24 12:31:16,285 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-05-24 12:31:16,285 INFO ipc.Server (Server.java:stop(968)) -
Stopping server on 38438
[junit] 2008-05-24 12:31:16,285 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 1 on 38438: exiting
[junit] 2008-05-24 12:31:16,286 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 0 on 38438: exiting
[junit] 2008-05-24 12:31:16,286 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 2 on 38438: exiting
[junit] 2008-05-24 12:31:16,287 INFO ipc.Server (Server.java:run(499)) -
Stopping IPC Server Responder
[junit] 2008-05-24 12:31:16,286 INFO dfs.DataNode
(DataNode.java:shutdown(541)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2008-05-24 12:31:16,288 INFO dfs.DataNode
(DataNode.java:run(2868)) - DatanodeRegistration(127.0.0.1:38436,
storageID=DS-928873062-140.211.11.106-38436-1211632272418, infoPort=38437,
ipcPort=38438):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-05-24 12:31:16,289 INFO dfs.DataBlockScanner
(DataBlockScanner.java:run(571)) - Exiting DataBlockScanner thread.
[junit] 2008-05-24 12:31:16,289 INFO http.SocketListener
(SocketListener.java:stop(212)) - Stopped SocketListener on 127.0.0.1:38434
[junit] 2008-05-24 12:31:16,290 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-05-24 12:31:16,290 INFO util.ThreadedServer
(ThreadedServer.java:run(656)) - Stopping Acceptor
ServerSocket[addr=localhost/127.0.0.1,port=0,localport=38434]
[junit] 2008-05-24 12:31:16,361 INFO util.Container
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
[junit] 2008-05-24 12:31:16,428 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
[junit] 2008-05-24 12:31:16,494 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
[junit] 2008-05-24 12:31:16,495 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-05-24 12:31:16,495 INFO ipc.Server (Server.java:stop(968)) -
Stopping server on 38435
[junit] 2008-05-24 12:31:16,496 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 0 on 38435: exiting
[junit] 2008-05-24 12:31:16,496 INFO ipc.Server (Server.java:run(327)) -
Stopping IPC Server listener on 38435
[junit] 2008-05-24 12:31:16,497 INFO ipc.Server (Server.java:run(499)) -
Stopping IPC Server Responder
[junit] 2008-05-24 12:31:16,497 INFO dfs.DataNode
(DataNode.java:shutdown(541)) - Waiting for threadgroup to exit, active threads
is 1
[junit] 2008-05-24 12:31:16,496 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 1 on 38435: exiting
[junit] 2008-05-24 12:31:16,498 INFO dfs.DataBlockScanner
(DataBlockScanner.java:run(571)) - Exiting DataBlockScanner thread.
[junit] 2008-05-24 12:31:16,498 INFO dfs.DataNode
(DataNode.java:run(2868)) - DatanodeRegistration(127.0.0.1:38433,
storageID=DS-378705661-140.211.11.106-38433-1211632271646, infoPort=38434,
ipcPort=38435):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-05-24 12:31:16,496 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 2 on 38435: exiting
[junit] 2008-05-24 12:31:16,500 INFO http.SocketListener
(SocketListener.java:stop(212)) - Stopped SocketListener on 0.0.0.0:38430
[junit] 2008-05-24 12:31:16,500 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-05-24 12:31:16,574 INFO util.ThreadedServer
(ThreadedServer.java:run(656)) - Stopping Acceptor
ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=38430]
[junit] 2008-05-24 12:31:16,576 INFO util.Container
(Container.java:stop(156)) - Stopped WebApplicationContext[/,/]
[junit] 2008-05-24 12:31:16,641 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/logs,/logs]
[junit] 2008-05-24 12:31:16,704 INFO util.Container
(Container.java:stop(156)) - Stopped HttpContext[/static,/static]
[junit] 2008-05-24 12:31:16,705 INFO util.Container
(Container.java:stop(156)) - Stopped [EMAIL PROTECTED]
[junit] 2008-05-24 12:31:16,706 WARN fs.FSNamesystem
(FSNamesystem.java:run(2053)) - ReplicationMonitor thread received
InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 2008-05-24 12:31:16,706 ERROR fs.FSNamesystem
(FSNamesystem.java:run(1731)) - 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:1708)
[junit] at java.lang.Thread.run(Thread.java:595)
[junit]
[junit] 2008-05-24 12:31:16,706 INFO fs.FSNamesystem
(FSEditLog.java:printStatistics(806)) - Number of transactions: 12 Total time
for transactions(ms): 1 Number of syncs: 10 SyncTimes(ms): 106 102
[junit] 2008-05-24 12:31:16,707 INFO ipc.Server (Server.java:stop(968)) -
Stopping server on 38429
[junit] 2008-05-24 12:31:16,707 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 3 on 38429: exiting
[junit] 2008-05-24 12:31:16,707 INFO ipc.Server (Server.java:run(327)) -
Stopping IPC Server listener on 38429
[junit] 2008-05-24 12:31:16,708 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 0 on 38429: exiting
[junit] 2008-05-24 12:31:16,708 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 1 on 38429: exiting
[junit] 2008-05-24 12:31:16,708 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 2 on 38429: exiting
[junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 17.629 sec
[junit] 2008-05-24 12:31:16,710 INFO ipc.Server (Server.java:run(499)) -
Stopping IPC Server Responder
[junit] 2008-05-24 12:31:16,710 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 9 on 38429: exiting
[junit] 2008-05-24 12:31:16,707 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 7 on 38429: exiting
[junit] 2008-05-24 12:31:16,711 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 4 on 38429: exiting
[junit] 2008-05-24 12:31:16,712 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 5 on 38429: exiting
[junit] 2008-05-24 12:31:16,712 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 6 on 38429: exiting
[junit] 2008-05-24 12:31:16,713 INFO ipc.Server (Server.java:run(899)) -
IPC Server handler 8 on 38429: exiting
[junit] Running org.apache.hadoop.security.TestUnixUserGroupInformation
[junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.439 sec
[junit] Running org.apache.hadoop.util.TestGenericsUtil
[junit] 2008-05-24 12:31:19,739 WARN util.GenericOptionsParser
(GenericOptionsParser.java:parseGeneralOptions(221)) - options parsing failed:
Missing argument for option:jt
[junit] usage: general options are:
[junit] -conf <configuration file> specify an application configuration
file
[junit] -D <property=value> use value for given property
[junit] -fs <local|namenode:port> specify a namenode
[junit] -jt <local|jobtracker:port> specify a job tracker
[junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.236 sec
[junit] Running org.apache.hadoop.util.TestIndexedSort
[junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.743 sec
[junit] Running org.apache.hadoop.util.TestReflectionUtils
[junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.657 sec
[junit] Running org.apache.hadoop.util.TestShell
[junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.28 sec
[junit] Running org.apache.hadoop.util.TestStringUtils
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.106 sec
BUILD FAILED
/zonestorage/hudson/home/hudson/hudson/jobs/Hadoop-trunk/workspace/trunk/build.xml:593:
Tests failed!
Total time: 81 minutes 51 seconds
Recording fingerprints
Publishing Javadoc
Recording test results
