search

trinodb / trino

Official repository of Trino, the distributed SQL query engine for big data, formerly known as PrestoSQL (https://trino.io)
https://trino.io
Apache License 2.0
10.46k stars 3.01k forks source link

Flaky test `TestPhoenixConnectorTest`: TimeoutException: The procedure 881 is still running #13957

Open findinpath opened 2 years ago

findinpath commented 2 years ago 
io.trino.plugin.phoenix5.TestPhoenixConnectorTest.testDelete  Time elapsed: 586.855 s  <<< FAILURE!
io.trino.testing.QueryFailedException: java.util.concurrent.TimeoutException: The procedure 881 is still running
    at io.trino.testing.AbstractTestingTrinoClient.execute(AbstractTestingTrinoClient.java:123)
    at io.trino.testing.AbstractTestingTrinoClient.execute(AbstractTestingTrinoClient.java:86)
    at io.trino.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:468)
    at io.trino.testing.sql.TestTable.close(TestTable.java:130)
    at io.trino.testing.BaseConnectorTest.testDelete(BaseConnectorTest.java:3187)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
    at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
    at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
    at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
    at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
    at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: io.trino.spi.TrinoException: java.util.concurrent.TimeoutException: The procedure 881 is still running
    at io.trino.plugin.jdbc.BaseJdbcClient.execute(BaseJdbcClient.java:974)
    at io.trino.plugin.jdbc.BaseJdbcClient.execute(BaseJdbcClient.java:960)
    at io.trino.plugin.phoenix5.PhoenixClient.execute(PhoenixClient.java:239)
    at io.trino.plugin.jdbc.BaseJdbcClient.dropTable(BaseJdbcClient.java:827)
    at io.trino.plugin.jdbc.BaseJdbcClient.dropTable(BaseJdbcClient.java:821)
    at io.trino.plugin.phoenix5.PhoenixMetadata.dropTable(PhoenixMetadata.java:264)
    at io.trino.plugin.base.classloader.ClassLoaderSafeConnectorMetadata.dropTable(ClassLoaderSafeConnectorMetadata.java:392)
    at io.trino.metadata.MetadataManager.dropTable(MetadataManager.java:756)
    at io.trino.execution.DropTableTask.execute(DropTableTask.java:89)
    at io.trino.execution.DropTableTask.execute(DropTableTask.java:37)
    at io.trino.execution.DataDefinitionExecution.start(DataDefinitionExecution.java:145)
    at io.trino.execution.SqlQueryManager.createQuery(SqlQueryManager.java:249)
    at io.trino.dispatcher.LocalDispatchQuery.lambda$startExecution$7(LocalDispatchQuery.java:143)
    at io.trino.$gen.Trino_testversion____20220901_053650_71.run(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
    Suppressed: java.lang.RuntimeException: Query: DROP TABLE "TPCH"."TEST_DELETE_1IZ67KPD3C"
        at io.trino.plugin.jdbc.BaseJdbcClient.execute(BaseJdbcClient.java:975)
        ... 16 more
Caused by: org.apache.phoenix.exception.PhoenixIOException: java.util.concurrent.TimeoutException: The procedure 881 is still running
    at org.apache.phoenix.util.ServerUtil.parseServerException(ServerUtil.java:138)
    at org.apache.phoenix.query.ConnectionQueryServicesImpl.dropTables(ConnectionQueryServicesImpl.java:2182)
    at org.apache.phoenix.query.ConnectionQueryServicesImpl.dropTable(ConnectionQueryServicesImpl.java:2070)
    at org.apache.phoenix.schema.MetaDataClient.dropTable(MetaDataClient.java:3450)
    at org.apache.phoenix.schema.MetaDataClient.dropTable(MetaDataClient.java:3358)
    at org.apache.phoenix.jdbc.PhoenixStatement$ExecutableDropTableStatement$1.execute(PhoenixStatement.java:1243)
    at org.apache.phoenix.jdbc.PhoenixStatement$2.call(PhoenixStatement.java:441)
    at org.apache.phoenix.jdbc.PhoenixStatement$2.call(PhoenixStatement.java:423)
    at org.apache.phoenix.call.CallRunner.run(CallRunner.java:53)
    at org.apache.phoenix.jdbc.PhoenixStatement.executeMutation(PhoenixStatement.java:422)
    at org.apache.phoenix.jdbc.PhoenixStatement.executeMutation(PhoenixStatement.java:410)
    at org.apache.phoenix.jdbc.PhoenixStatement.execute(PhoenixStatement.java:1986)
    at io.trino.plugin.jdbc.BaseJdbcClient.execute(BaseJdbcClient.java:971)
    ... 16 more
Caused by: org.apache.hadoop.hbase.exceptions.TimeoutIOException: java.util.concurrent.TimeoutException: The procedure 881 is still running
    at org.apache.hadoop.hbase.client.HBaseAdmin.get(HBaseAdmin.java:2203)
    at org.apache.hadoop.hbase.client.HBaseAdmin.deleteTable(HBaseAdmin.java:716)
    at org.apache.phoenix.query.ConnectionQueryServicesImpl.dropTables(ConnectionQueryServicesImpl.java:2173)
    ... 27 more
Caused by: java.util.concurrent.TimeoutException: The procedure 881 is still running
    at org.apache.hadoop.hbase.client.HBaseAdmin$ProcedureFuture.waitProcedureResult(HBaseAdmin.java:3566)
    at org.apache.hadoop.hbase.client.HBaseAdmin$ProcedureFuture.get(HBaseAdmin.java:3487)
    at org.apache.hadoop.hbase.client.HBaseAdmin.get(HBaseAdmin.java:2197)
    ... 29 more
findinpath commented 2 years ago

https://github.com/trinodb/trino/runs/8128351678?check_suite_focus=true

findinpath commented 2 years ago

https://github.com/trinodb/trino/actions/runs/3240661293/jobs/5312076179

findepi commented 1 year ago

Can happen in other test methods too, for example https://github.com/trinodb/trino/actions/runs/4013642902/jobs/6893975330

Error:  Tests run: 520, Failures: 1, Errors: 0, Skipped: 205, Time elapsed: 1,252.391 s <<< FAILURE! - in TestSuite
Error:  io.trino.plugin.phoenix5.TestPhoenixConnectorTest.testDataMappingSmokeTest[bigint:312739231274942432](5)  Time elapsed: 570.793 s  <<< FAILURE!
io.trino.testing.QueryFailedException: java.util.concurrent.TimeoutException: The procedure 840 is still running
    at io.trino.testing.AbstractTestingTrinoClient.execute(AbstractTestingTrinoClient.java:122)
    at io.trino.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:490)
    at io.trino.testing.QueryAssertions.assertUpdate(QueryAssertions.java:71)
    at io.trino.testing.AbstractTestQueryFramework.assertUpdate(AbstractTestQueryFramework.java:365)
    at io.trino.testing.AbstractTestQueryFramework.assertUpdate(AbstractTestQueryFramework.java:360)
    at io.trino.testing.BaseConnectorTest.testDataMapping(BaseConnectorTest.java:4561)
    at io.trino.testing.BaseConnectorTest.testDataMappingSmokeTest(BaseConnectorTest.java:4506)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
    at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
    at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
    at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
    at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
    at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
    Suppressed: java.lang.Exception: SQL: DROP TABLE test_data_mapping_smoke_bigint_q05vmx7b0u
        at io.trino.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:493)
        ... 18 more
Caused by: io.trino.spi.TrinoException: java.util.concurrent.TimeoutException: The procedure 840 is still running
    at io.trino.plugin.jdbc.BaseJdbcClient.execute(BaseJdbcClient.java:1166)
    at io.trino.plugin.phoenix5.PhoenixClient.execute(PhoenixClient.java:246)
    at io.trino.plugin.jdbc.BaseJdbcClient.dropTable(BaseJdbcClient.java:1010)
    at io.trino.plugin.jdbc.BaseJdbcClient.dropTable(BaseJdbcClient.java:1004)
    at io.trino.plugin.phoenix5.PhoenixMetadata.dropTable(PhoenixMetadata.java:273)
    at io.trino.plugin.base.classloader.ClassLoaderSafeConnectorMetadata.dropTable(ClassLoaderSafeConnectorMetadata.java:391)
    at io.trino.metadata.MetadataManager.dropTable(MetadataManager.java:796)
    at io.trino.execution.DropTableTask.execute(DropTableTask.java:89)
    at io.trino.execution.DropTableTask.execute(DropTableTask.java:37)
    at io.trino.execution.DataDefinitionExecution.start(DataDefinitionExecution.java:145)
    at io.trino.execution.SqlQueryManager.createQuery(SqlQueryManager.java:249)
    at io.trino.dispatcher.LocalDispatchQuery.lambda$startExecution$7(LocalDispatchQuery.java:143)
    at io.trino.$gen.Trino_testversion____20230126_104325_71.run(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: org.apache.phoenix.exception.PhoenixIOException: java.util.concurrent.TimeoutException: The procedure 840 is still running
    at org.apache.phoenix.util.ServerUtil.parseServerException(ServerUtil.java:138)
    at org.apache.phoenix.query.ConnectionQueryServicesImpl.dropTables(ConnectionQueryServicesImpl.java:2182)
    at org.apache.phoenix.query.ConnectionQueryServicesImpl.dropTable(ConnectionQueryServicesImpl.java:2070)
    at org.apache.phoenix.schema.MetaDataClient.dropTable(MetaDataClient.java:3450)
    at org.apache.phoenix.schema.MetaDataClient.dropTable(MetaDataClient.java:3358)
    at org.apache.phoenix.jdbc.PhoenixStatement$ExecutableDropTableStatement$1.execute(PhoenixStatement.java:1243)
    at org.apache.phoenix.jdbc.PhoenixStatement$2.call(PhoenixStatement.java:441)
    at org.apache.phoenix.jdbc.PhoenixStatement$2.call(PhoenixStatement.java:423)
    at org.apache.phoenix.call.CallRunner.run(CallRunner.java:53)
    at org.apache.phoenix.jdbc.PhoenixStatement.executeMutation(PhoenixStatement.java:422)
    at org.apache.phoenix.jdbc.PhoenixStatement.executeMutation(PhoenixStatement.java:410)
    at org.apache.phoenix.jdbc.PhoenixStatement.execute(PhoenixStatement.java:1986)
    at io.trino.plugin.jdbc.BaseJdbcClient.execute(BaseJdbcClient.java:1176)
    at io.trino.plugin.jdbc.BaseJdbcClient.execute(BaseJdbcClient.java:1163)
    ... 15 more
    Suppressed: java.lang.RuntimeException: Query: DROP TABLE "TPCH"."TEST_DATA_MAPPING_SMOKE_BIGINT_Q05VMX7B0U"
        at io.trino.plugin.jdbc.BaseJdbcClient.execute(BaseJdbcClient.java:1179)
        ... 16 more
Caused by: org.apache.hadoop.hbase.exceptions.TimeoutIOException: java.util.concurrent.TimeoutException: The procedure 840 is still running
    at org.apache.hadoop.hbase.client.HBaseAdmin.get(HBaseAdmin.java:2203)
    at org.apache.hadoop.hbase.client.HBaseAdmin.deleteTable(HBaseAdmin.java:716)
    at org.apache.phoenix.query.ConnectionQueryServicesImpl.dropTables(ConnectionQueryServicesImpl.java:2173)
    ... 27 more
Caused by: java.util.concurrent.TimeoutException: The procedure 840 is still running
    at org.apache.hadoop.hbase.client.HBaseAdmin$ProcedureFuture.waitProcedureResult(HBaseAdmin.java:3566)
    at org.apache.hadoop.hbase.client.HBaseAdmin$ProcedureFuture.get(HBaseAdmin.java:3487)
    at org.apache.hadoop.hbase.client.HBaseAdmin.get(HBaseAdmin.java:2197)
    ... 29 more
findepi commented 1 year ago

cc @wendigo @vincentpoon @lhofhansl