See https://hudson.apache.org/hudson/job/Hadoop-Hdfs-trunk/539/
###################################################################################
########################## LAST 60 LINES OF THE CONSOLE
###########################
[...truncated 375110 lines...]
[junit] 2011-01-01 13:31:37,273 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:40,273 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:40,274 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:40,274 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:40,274 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:40,274 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:40,274 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:40,274 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:40,275 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:40,275 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:40,275 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:40,275 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:40,275 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:43,276 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:43,276 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:43,276 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:43,276 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:43,277 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:43,277 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:43,277 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:43,277 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:43,277 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:43,278 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:43,278 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:43,278 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:46,279 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:46,279 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:46,279 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:46,279 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:46,279 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:46,279 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:46,280 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:46,280 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:46,280 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:46,280 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:46,280 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:46,281 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:49,281 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:49,281 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:49,282 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:49,282 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:49,282 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:49,282 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:49,282 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:49,282 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:49,283 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:49,283 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
[junit] 2011-01-01 13:31:49,283 DEBUG namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:isGoodTarget(413)) - Node
/default-rack/127.0.0.1:47342 is not chosen because the node is too busy
[junit] 2011-01-01 13:31:49,283 WARN namenode.FSNamesystem
(BlockPlacementPolicyDefault.java:chooseTarget(190)) - Not able to place enough
replicas, still in need of 1
Build timed out. Aborting
[FINDBUGS] Skipping publisher since build result is FAILURE
Publishing Javadoc
Archiving artifacts
Recording test results
Recording fingerprints
Publishing Clover coverage report...
No Clover report will be published due to a Build Failure
Email was triggered for: Failure
Sending email for trigger: Failure
###################################################################################
############################## FAILED TESTS (if any)
##############################
4 tests failed.
REGRESSION: org.apache.hadoop.hdfs.TestFileAppend3.testAppendToPartialChunk
Error Message:
Lease mismatch on /partialChunk/foo owned by HDFS_NameNode but is accessed by
DFSClient_NONMAPREDUCE_1664622238_1 at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:1673)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:1648)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.completeFileInternal(FSNamesystem.java:1703)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.completeFile(FSNamesystem.java:1686)
at
org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:853) at
sun.reflect.GeneratedMethodAccessor8.invoke(Unknown Source) at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597) at
org.apache.hadoop.ipc.WritableRpcEngine$Server.call(WritableRpcEngine.java:351)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1399) at
org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1395) at
java.security.AccessController.doPrivileged(Native Method) at
javax.security.auth.Subject.doAs(Subject.java:396) at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1115)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1393)
Stack Trace:
org.apache.hadoop.hdfs.server.namenode.LeaseExpiredException: Lease mismatch on
/partialChunk/foo owned by HDFS_NameNode but is accessed by
DFSClient_NONMAPREDUCE_1664622238_1
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:1673)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkLease(FSNamesystem.java:1648)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.completeFileInternal(FSNamesystem.java:1703)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.completeFile(FSNamesystem.java:1686)
at
org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:853)
at
org.apache.hadoop.ipc.WritableRpcEngine$Server.call(WritableRpcEngine.java:351)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1399)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1395)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:396)
at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1115)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1393)
at org.apache.hadoop.ipc.Client.call(Client.java:1028)
at
org.apache.hadoop.ipc.WritableRpcEngine$Invoker.invoke(WritableRpcEngine.java:198)
at $Proxy7.complete(Unknown Source)
at
org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:84)
at
org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
at $Proxy7.complete(Unknown Source)
at
org.apache.hadoop.hdfs.DFSOutputStream.completeFile(DFSOutputStream.java:1502)
at
org.apache.hadoop.hdfs.DFSOutputStream.close(DFSOutputStream.java:1489)
at
org.apache.hadoop.fs.FSDataOutputStream$PositionCache.close(FSDataOutputStream.java:66)
at
org.apache.hadoop.fs.FSDataOutputStream.close(FSDataOutputStream.java:91)
at
org.apache.hadoop.hdfs.TestFileAppend3.__CLR3_0_2i84krqr3r(TestFileAppend3.java:353)
at
org.apache.hadoop.hdfs.TestFileAppend3.testAppendToPartialChunk(TestFileAppend3.java:311)
at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
at junit.extensions.TestSetup$1.protect(TestSetup.java:23)
at junit.extensions.TestSetup.run(TestSetup.java:27)
FAILED: TEST-org.apache.hadoop.hdfs.TestFileCreationClient.xml.<init>
Error Message:
Stack Trace:
Test report file
/grid/0/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/TEST-org.apache.hadoop.hdfs.TestFileCreationClient.xml
was length 0
FAILED: org.apache.hadoop.hdfs.TestDFSStorageStateRecovery.testDNStorageStates
Error Message:
Timeout occurred. Please note the time in the report does not reflect the time
until the timeout.
Stack Trace:
junit.framework.AssertionFailedError: Timeout occurred. Please note the time in
the report does not reflect the time until the timeout.
FAILED:
org.apache.hadoop.hdfs.server.namenode.TestStorageRestore.testStorageRestore
Error Message:
Image file
/grid/0/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/secondary/current/fsimage
is corrupt with MD5 checksum of 69d1774e121411506c39a356a8edb105 but expecting
2cae312c103ccdb1032bc8bc19376950
Stack Trace:
java.io.IOException: Image file
/grid/0/hudson/hudson-slave/workspace/Hadoop-Hdfs-trunk/trunk/build/test/data/dfs/secondary/current/fsimage
is corrupt with MD5 checksum of 69d1774e121411506c39a356a8edb105 but expecting
2cae312c103ccdb1032bc8bc19376950
at
org.apache.hadoop.hdfs.server.namenode.FSImage.loadFSImage(FSImage.java:1063)
at
org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode$CheckpointStorage.doMerge(SecondaryNameNode.java:702)
at
org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode$CheckpointStorage.access$500(SecondaryNameNode.java:600)
at
org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode.doMerge(SecondaryNameNode.java:477)
at
org.apache.hadoop.hdfs.server.namenode.SecondaryNameNode.doCheckpoint(SecondaryNameNode.java:438)
at
org.apache.hadoop.hdfs.server.namenode.TestStorageRestore.__CLR3_0_2dn2tm4tjm(TestStorageRestore.java:316)
at
org.apache.hadoop.hdfs.server.namenode.TestStorageRestore.testStorageRestore(TestStorageRestore.java:286)
