Pratyush Bhatt created HBASE-27893:
--------------------------------------
Summary: IntegrationTestManyRegions fails with "Failed to create
table"
Key: HBASE-27893
URL: https://issues.apache.org/jira/browse/HBASE-27893
Project: HBase
Issue Type: Bug
Reporter: Pratyush Bhatt
Running Integration test on Hbase(Configured to run over Ozone) as follows:
{noformat}
hbase org.apache.hadoop.hbase.IntegrationTestsDriver -regex
IntegrationTestManyRegions {noformat}
The test fails with the below error:
{noformat}
2023-05-25 09:10:15,506|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|23/05/25 09:10:15 INFO
zookeeper.ZooKeeper: Session: 0x30587a0caee0917 closed
2023-05-25 09:10:15,507|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|23/05/25 09:10:15 INFO
zookeeper.ClientCnxn: EventThread shut down for session: 0x30587a0caee0917
2023-05-25 09:19:40,083|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|23/05/25 09:19:40 ERROR
hbase.IntegrationTestManyRegions: Failed to create table
2023-05-25 09:19:40,083|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|org.apache.hadoop.hbase.exceptions.TimeoutIOException:
java.util.concurrent.TimeoutException: The procedure 489 is still running
2023-05-25 09:19:40,084|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:188)
2023-05-25 09:19:40,084|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.client.Admin.createTable(Admin.java:349)
2023-05-25 09:19:40,084|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.IntegrationTestManyRegions.testCreateTableWithRegions(IntegrationTestManyRegions.java:111)
2023-05-25 09:19:40,084|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-05-25 09:19:40,084|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2023-05-25 09:19:40,084|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2023-05-25 09:19:40,085|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
java.lang.reflect.Method.invoke(Method.java:498)
2023-05-25 09:19:40,085|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
2023-05-25 09:19:40,085|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
2023-05-25 09:19:40,085|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
2023-05-25 09:19:40,085|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
2023-05-25 09:19:40,085|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
2023-05-25 09:19:40,086|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
2023-05-25 09:19:40,086|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
2023-05-25 09:19:40,086|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
2023-05-25 09:19:40,086|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
2023-05-25 09:19:40,086|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
2023-05-25 09:19:40,086|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
2023-05-25 09:19:40,086|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
2023-05-25 09:19:40,087|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
2023-05-25 09:19:40,087|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
2023-05-25 09:19:40,087|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
2023-05-25 09:19:40,087|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
2023-05-25 09:19:40,087|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:299)
2023-05-25 09:19:40,087|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:293)
2023-05-25 09:19:40,088|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
java.util.concurrent.FutureTask.run(FutureTask.java:266)
2023-05-25 09:19:40,088|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
java.lang.Thread.run(Thread.java:750)
2023-05-25 09:19:40,088|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|Caused by:
java.util.concurrent.TimeoutException: The procedure 489 is still running
2023-05-25 09:19:40,088|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.client.HBaseAdmin$ProcedureFuture.waitProcedureResult(HBaseAdmin.java:3460)
2023-05-25 09:19:40,088|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.client.HBaseAdmin$ProcedureFuture.get(HBaseAdmin.java:3382)
2023-05-25 09:19:40,088|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:182)
2023-05-25 09:19:40,088|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|... 26 more
2023-05-25 09:19:40,089|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|23/05/25 09:19:40 INFO
hbase.IntegrationTestManyRegions: Cleaning up after test.
2023-05-25 09:20:52,904|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|23/05/25 09:20:52 INFO
client.HBaseAdmin: Operation: DELETE, Table Name:
default:IntegrationTestManyRegions, procId: 2490 failed with Not DISABLED;
tableName=IntegrationTestManyRegions, state=ENABLED
2023-05-25 09:20:52,921|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|E
2023-05-25 09:20:52,925|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|Time: 699.256
2023-05-25 09:20:52,926|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|There was 1 failure:
2023-05-25 09:20:52,926|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|1)
testCreateTableWithRegions(org.apache.hadoop.hbase.IntegrationTestManyRegions)
2023-05-25 09:20:52,933|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|org.apache.hadoop.hbase.TableNotDisabledException:
Not DISABLED; tableName=IntegrationTestManyRegions, state=ENABLED
2023-05-25 09:20:52,933|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
java.lang.Thread.getStackTrace(Thread.java:1564)
2023-05-25 09:20:52,934|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.util.FutureUtils.setStackTrace(FutureUtils.java:130)
2023-05-25 09:20:52,934|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.util.FutureUtils.rethrow(FutureUtils.java:149)
2023-05-25 09:20:52,934|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:186)
2023-05-25 09:20:52,934|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.client.Admin.deleteTable(Admin.java:389)
2023-05-25 09:20:52,935|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|at
org.apache.hadoop.hbase.IntegrationTestManyRegions.tearDown(IntegrationTestManyRegions.java:94)
2023-05-25 09:20:52,935|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|
2023-05-25 09:20:52,935|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|FAILURES!!!
2023-05-25 09:20:52,935|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|Tests run: 1, Failures: 1
2023-05-25 09:20:52,936|INFO|MainThread|machine.py:203 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|
2023-05-25 09:20:53,283|INFO|MainThread|machine.py:232 -
run()||GUID=5079831e-fed2-4115-a0ea-6e82f7cfa8df|Exit Code: 1
2023-05-25 09:20:53,283|INFO|MainThread|machine.py:238 - run()|Command
/opt/cloudera/parcels/CDH/bin/hbase
org.apache.hadoop.hbase.IntegrationTestsDriver -regex
IntegrationTestManyRegions failed after 0 retries
2023-05-25 09:20:53,297|INFO|MainThread|conftest.py:267 -
pytest_report_teststatus()|TEST "test_runIntegrationTestManyRegions" FAILED in
705.79 seconds{noformat}
I tried checking the HMaster logs during the same TS:
{noformat}
2023-05-25 09:10:02,290 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-7.ozn-lease19.root.hwx.site,22101,1685005607425
transition on state=OPEN,
location=ozn-lease19-7.ozn-lease19.root.hwx.site,22101,1685005607425,
table=IntegrationTestManyRegions, region=00967afde53476a802ae025287abef56 to
OPENED
2023-05-25 09:10:02,290 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-3.ozn-lease19.root.hwx.site,22101,1685005608921
transition on state=OPEN,
location=ozn-lease19-3.ozn-lease19.root.hwx.site,22101,1685005608921,
table=IntegrationTestManyRegions, region=daadf5da9520987e5dcbe20cabe1ce80 to
OPENED
2023-05-25 09:10:02,290 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-2.ozn-lease19.root.hwx.site,22101,1685005606403
transition on state=OPEN,
location=ozn-lease19-2.ozn-lease19.root.hwx.site,22101,1685005606403,
table=IntegrationTestManyRegions, region=199e3c7dd843b86d8ad753a1dcc85105 to
OPENED
2023-05-25 09:10:02,291 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-5.ozn-lease19.root.hwx.site,22101,1685005607684
transition on state=OPEN,
location=ozn-lease19-5.ozn-lease19.root.hwx.site,22101,1685005607684,
table=IntegrationTestManyRegions, region=61f7fccb0eefea5e3586b2c4d61e3c83 to
OPENED
2023-05-25 09:10:02,291 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-6.ozn-lease19.root.hwx.site,22101,1685005608861
transition on state=OPEN,
location=ozn-lease19-6.ozn-lease19.root.hwx.site,22101,1685005608861,
table=IntegrationTestManyRegions, region=48840208b5165a994e82bb3dc09eb0ce to
OPENED
2023-05-25 09:10:02,292 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-6.ozn-lease19.root.hwx.site,22101,1685005608861
transition on state=OPEN,
location=ozn-lease19-6.ozn-lease19.root.hwx.site,22101,1685005608861,
table=IntegrationTestManyRegions, region=0cbe633670f5f124a4107250afd2079e to
OPENED
2023-05-25 09:10:02,292 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-6.ozn-lease19.root.hwx.site,22101,1685005608861
transition on state=OPEN,
location=ozn-lease19-6.ozn-lease19.root.hwx.site,22101,1685005608861,
table=IntegrationTestManyRegions, region=5b0f726d4f59fb29fd153d8ea0730948 to
OPENED
2023-05-25 09:10:02,292 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-8.ozn-lease19.root.hwx.site,22101,1685005606965
transition on state=OPEN,
location=ozn-lease19-8.ozn-lease19.root.hwx.site,22101,1685005606965,
table=IntegrationTestManyRegions, region=d8e74d20dcdb38774d44aca7a195811e to
OPENED
2023-05-25 09:10:02,293 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-1.ozn-lease19.root.hwx.site,22101,1685005608089
transition on state=OPEN,
location=ozn-lease19-1.ozn-lease19.root.hwx.site,22101,1685005608089,
table=IntegrationTestManyRegions, region=767d263b1a5519398525c21de6be92fb to
OPENED
2023-05-25 09:10:02,293 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-3.ozn-lease19.root.hwx.site,22101,1685005608921
transition on state=OPEN,
location=ozn-lease19-3.ozn-lease19.root.hwx.site,22101,1685005608921,
table=IntegrationTestManyRegions, region=93d06d0830a5009b8a50f4ff85eb0338 to
OPENED
2023-05-25 09:10:02,294 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-1.ozn-lease19.root.hwx.site,22101,1685005608089
transition on state=OPEN,
location=ozn-lease19-1.ozn-lease19.root.hwx.site,22101,1685005608089,
table=IntegrationTestManyRegions, region=c230ebb6c6fe4f3d59c9015b136108b5 to
OPENED
2023-05-25 09:10:02,294 WARN
org.apache.hadoop.hbase.master.assignment.AssignmentManager: No matching
procedure found for ozn-lease19-7.ozn-lease19.root.hwx.site,22101,1685005607425
transition on state=OPEN,
location=ozn-lease19-7.ozn-lease19.root.hwx.site,22101,1685005607425,
table=IntegrationTestManyRegions, region=d57326297360ffb56f1fe929c0ed1c1c to
OPENED
2023-05-25 09:10:02,316 INFO
org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL: Slow sync cost: 424 ms,
current pipeline: []{noformat}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
