stack created HBASE-9368: ---------------------------- Summary: TestDistributedLogSplitting.testDelayedDeleteOnFailure fails on occasion Key: HBASE-9368 URL: https://issues.apache.org/jira/browse/HBASE-9368 Project: HBase Issue Type: Bug Components: test Reporter: stack
Follow on from hbase-8567. See https://builds.apache.org/view/H-L/view/HBase/job/hbase-0.95-on-hadoop2/275/testReport/junit/org.apache.hadoop.hbase.master/TestDistributedLogSplitting/testDelayedDeleteOnFailure/ {code} org.apache.hadoop.hbase.master.TestDistributedLogSplitting.testDelayedDeleteOnFailure Failing for the past 1 build (Since Failed#275 ) Took 7 ms. add description Error Message test timed out after 30000 milliseconds Stacktrace java.lang.Exception: test timed out after 30000 milliseconds at java.lang.Thread.start0(Native Method) at java.lang.Thread.start(Thread.java:640) at org.apache.zookeeper.ClientCnxn.start(ClientCnxn.java:403) at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:450) at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:380) at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.<init>(RecoverableZooKeeper.java:114) at org.apache.hadoop.hbase.zookeeper.ZKUtil.connect(ZKUtil.java:135) at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:167) at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:136) at org.apache.hadoop.hbase.client.ZooKeeperKeepAliveConnection.<init>(ZooKeeperKeepAliveConnection.java:43) at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.getKeepAliveZooKeeperWatcher(HConnectionManager.java:1788) at org.apache.hadoop.hbase.client.ZooKeeperRegistry.getClusterId(ZooKeeperRegistry.java:82) at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.retrieveClusterId(HConnectionManager.java:778) at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.<init>(HConnectionManager.java:618) at sun.reflect.GeneratedConstructorAccessor38.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) at java.lang.reflect.Constructor.newInstance(Constructor.java:513) at org.apache.hadoop.hbase.client.HConnectionManager.createConnection(HConnectionManager.java:377) at org.apache.hadoop.hbase.client.HConnectionManager.createConnection(HConnectionManager.java:358) at org.apache.hadoop.hbase.client.HConnectionManager.getConnection(HConnectionManager.java:293) at org.apache.hadoop.hbase.client.HTable.<init>(HTable.java:191) at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster(HBaseTestingUtility.java:887) at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster(HBaseTestingUtility.java:853) at org.apache.hadoop.hbase.master.TestDistributedLogSplitting.startCluster(TestDistributedLogSplitting.java:156) at org.apache.hadoop.hbase.master.TestDistributedLogSplitting.startCluster(TestDistributedLogSplitting.java:141) at org.apache.hadoop.hbase.master.TestDistributedLogSplitting.testDelayedDeleteOnFailure(TestDistributedLogSplitting.java:970) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.internal.runners.statements.FailOnTimeout$StatementThread.run(FailOnTimeout.java:74) {code} We seem stuck. Nothing happens after master initializes... we just wait: {code} 2013-08-28 00:42:53,492 INFO [M:0;quirinus:56658] master.HMaster(901): Master has completed initialization 2013-08-28 00:42:53,496 DEBUG [NamespaceJanitor-quirinus:56658] client.ClientScanner(218): Finished {ENCODED => 5fb8721e18f122319e47336ad5221a58, NAME => 'hbase:namespace,,1377650558736.5fb8721e18f122319e47336ad5221a58.', STARTKEY => '', ENDKEY => ''} 2013-08-28 00:42:53,534 DEBUG [CatalogJanitor-quirinus:56658] client.ClientScanner(218): Finished {ENCODED => 1588230740, NAME => 'hbase:meta,,1', STARTKEY => '', ENDKEY => ''} 2013-08-28 00:43:34,443 INFO [Thread-2407] zookeeper.RecoverableZooKeeper(122): Process identifier=hconnection-0x958cd8 connecting to ZooKeeper ensemble=localhost:60031 2013-08-28 00:43:34,443 FATAL [pool-1-thread-1] master.HMaster(2240): Master server abort: loaded coprocessors are: [org.apache.hadoop.hbase.coprocessor.MultiRowMutationEndpoint] 2013-08-28 00:43:34,443 FATAL [pool-1-thread-1] master.HMaster(2245): closing... java.lang.Exception: Trace info at org.apache.hadoop.hbase.master.TestDistributedLogSplitting.after(TestDistributedLogSplitting.java:169) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) at org.junit.runners.ParentRunner.run(ParentRunner.java:309) at org.junit.runners.Suite.runChild(Suite.java:127) at org.junit.runners.Suite.runChild(Suite.java:26) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918) at java.lang.Thread.run(Thread.java:662) 2013-08-28 00:43:34,444 INFO [pool-1-thread-1] master.HMaster(2434): Aborting 2013-08-28 00:43:34,443 WARN [Thread-2407] zookeeper.ZKUtil(489): hconnection-0x958cd8 Unable to set watcher on znode (/hbase/hbaseid) java.lang.InterruptedException at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:485) at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1309) at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1036) at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.exists(RecoverableZooKeeper.java:202) at org.apache.hadoop.hbase.zookeeper.ZKUtil.checkExists(ZKUtil.java:482) at org.apache.hadoop.hbase.zookeeper.ZKClusterId.readClusterIdZNode(ZKClusterId.java:65) at org.apache.hadoop.hbase.client.ZooKeeperRegistry.getClusterId(ZooKeeperRegistry.java:83) at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.retrieveClusterId(HConnectionManager.java:778) at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.<init>(HConnectionManager.java:618) at sun.reflect.GeneratedConstructorAccessor38.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) at java.lang.reflect.Constructor.newInstance(Constructor.java:513) at org.apache.hadoop.hbase.client.HConnectionManager.createConnection(HConnectionManager.java:377) at org.apache.hadoop.hbase.client.HConnectionManager.createConnection(HConnectionManager.java:358) at org.apache.hadoop.hbase.client.HConnectionManager.getConnection(HConnectionManager.java:293) at org.apache.hadoop.hbase.client.HTable.<init>(HTable.java:191) at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster(HBaseTestingUtility.java:887) at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster(HBaseTestingUtility.java:853) at org.apache.hadoop.hbase.master.TestDistributedLogSplitting.startCluster(TestDistributedLogSplitting.java:156) at org.apache.hadoop.hbase.master.TestDistributedLogSplitting.startCluster(TestDistributedLogSplitting.java:141) at org.apache.hadoop.hbase.master.TestDistributedLogSplitting.testDelayedDeleteOnFailure(TestDistributedLogSplitting.java:970) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.internal.runners.statements.FailOnTimeout$StatementThread.run(FailOnTimeout.java:74) ... {code} What you think [~jeffreyz]? Thanks boss. -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira