hadoop-common-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Hudson Server <hud...@hudson.zones.apache.org>
Subject Build failed in Hudson: Hadoop-trunk #420
Date Wed, 05 Mar 2008 16:02:30 GMT
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
org.mortbay.jetty.servlet.WebApplicationHandler@1417690
    [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
org.mortbay.jetty.Server@160c4b0
    [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: org.apache.hadoop.dfs.PermissionChecker@1c6a99d, 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: org.apache.hadoop.dfs.PermissionChecker@1762fc7, 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: org.apache.hadoop.dfs.PermissionChecker@3aef16, 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: org.apache.hadoop.dfs.PermissionChecker@126c6ea, 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
org.mortbay.jetty.servlet.WebApplicationHandler@1417690
    [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
org.mortbay.jetty.Server@160c4b0
    [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
org.mortbay.jetty.servlet.WebApplicationHandler@16f70a4
    [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
org.mortbay.jetty.Server@19b4748
    [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
org.mortbay.jetty.servlet.WebApplicationHandler@9b688e
    [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
org.mortbay.jetty.Server@17cd15d
    [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
org.mortbay.jetty.servlet.WebApplicationHandler@898540
    [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
org.mortbay.jetty.Server@4d41e2
    [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


Mime
View raw message