Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

io.trino.plugin.hive.TestHive3InsertOverwrite flaky: Schema already exists: 'hive_insert_overwrite' #9415

Closed
losipiuk opened this issue Sep 28, 2021 · 10 comments
Labels

Comments

@losipiuk
Copy link
Member

Error:  Tests run: 2959, Failures: 1, Errors: 0, Skipped: 103, Time elapsed: 1,987.38 s <<< FAILURE! - in TestSuite
Error:  io.trino.plugin.hive.TestHive3InsertOverwrite.setUp  Time elapsed: 370.656 s  <<< FAILURE!
java.lang.RuntimeException: Schema already exists: 'hive_insert_overwrite'
	at io.trino.testing.AbstractTestingTrinoClient.execute(AbstractTestingTrinoClient.java:119)
	at io.trino.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:476)
	at io.trino.testing.AbstractTestQueryFramework.computeActual(AbstractTestQueryFramework.java:151)
	at io.trino.testing.AbstractTestQueryFramework.computeActual(AbstractTestQueryFramework.java:146)
	at io.trino.plugin.hive.BaseTestHiveInsertOverwrite.setUp(BaseTestHiveInsertOverwrite.java:72)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
	at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:515)
	at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:217)
	at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:144)
	at org.testng.internal.TestMethodWorker.invokeBeforeClassMethods(TestMethodWorker.java:169)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:108)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
	Suppressed: java.lang.Exception: SQL: CREATE SCHEMA hive.hive_insert_overwrite WITH (location='s3a://test-hive-insert-overwrite-1s0whocfzw/hive_insert_overwrite')
		at io.trino.testing.DistributedQueryRunner.execute(DistributedQueryRunner.java:479)
		... 16 more
Caused by: io.trino.plugin.hive.SchemaAlreadyExistsException: Schema already exists: 'hive_insert_overwrite'
	at io.trino.plugin.hive.metastore.thrift.ThriftHiveMetastore.createDatabase(ThriftHiveMetastore.java:999)
	at io.trino.plugin.hive.metastore.thrift.BridgingHiveMetastore.createDatabase(BridgingHiveMetastore.java:163)
	at io.trino.plugin.hive.metastore.cache.CachingHiveMetastore.createDatabase(CachingHiveMetastore.java:470)
	at io.trino.plugin.hive.HiveMetastoreClosure.createDatabase(HiveMetastoreClosure.java:130)
	at io.trino.plugin.hive.metastore.SemiTransactionalHiveMetastore.lambda$createDatabase$2(SemiTransactionalHiveMetastore.java:361)
	at io.trino.plugin.hive.metastore.SemiTransactionalHiveMetastore.commit(SemiTransactionalHiveMetastore.java:1170)
	at io.trino.plugin.hive.HiveMetadata.commit(HiveMetadata.java:3026)
	at io.trino.plugin.hive.HiveConnector.commit(HiveConnector.java:225)
	at io.trino.transaction.InMemoryTransactionManager$TransactionMetadata$ConnectorTransactionMetadata.commit(InMemoryTransactionManager.java:613)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
	at io.airlift.concurrent.BoundedExecutor.drainQueue(BoundedExecutor.java:80)
	at io.trino.$gen.Trino_testversion____20210928_135143_9883.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

test run: https://github.com/trinodb/trino/runs/3732417093?check_suite_focus=true

@losipiuk losipiuk added the test label Sep 28, 2021
@losipiuk
Copy link
Member Author

@aczajkowski PTAL

@aczajkowski
Copy link
Member

@losipiuk PR to address issue: #9421

@aczajkowski
Copy link
Member

Seems that issue occurred due to below scenario:

  1. Hadoop container A starts for TestHive2InsertOverwrite (Thread 1)
  2. Hadoop container A maps random port A1 for HMS (Thread 1)
  3. At this state HMS in container A should be empty as it just started (Thread 1)
  4. TestHive2InsertOverwrite created metadata for SCHEMA via A1 port (Thread 1)
  5. Hadoop container B starts for TestHive3InsertOverwrite (Thread 2)
  6. Hadoop container B maps random port B1 for HMS (Thread 2)
  7. At this state HMS in container B should be empty as it just started (Thread 2)
  8. TestHive3InsertOverwrite created metadata for SCHEMA via B1 port (Thread 2)

But for some reason step 8 ends with SchemaAllreadyExists which leads to assumption that for some reason second test
was pointed to wrong Port pointing to other HMS. But looking at code it should be impossible.
So I'm in a dead end.
I'm unable to reproduce this case locally so I just applied changes which removes some unnecessary redundancy and assures schemas has always different names per test. Which is a kind of prevention rather than real fix.

@aczajkowski
Copy link
Member

PR to help debug this issue: #9449

@joshthoward
Copy link
Member

Hit by #9715

@findepi findepi changed the title io.trino.plugin.hive.TestHive3InsertOverwrite flaky io.trino.plugin.hive.TestHive3InsertOverwrite flaky: Schema already exists: 'hive_insert_overwrite' Dec 6, 2021
@sopel39
Copy link
Member

sopel39 commented Dec 10, 2021

@findepi
Copy link
Member

findepi commented Jan 13, 2022

This time Schema already exists: 'tpch':

2022-01-13T12:02:48.7195826Z [ERROR] io.trino.plugin.hive.TestHive3InsertOverwrite.init  Time elapsed: 6.281 s  <<< FAILURE!
2022-01-13T12:02:48.7197930Z io.trino.plugin.hive.SchemaAlreadyExistsException: Schema already exists: 'tpch'
2022-01-13T12:02:48.7200325Z 	at io.trino.plugin.hive.metastore.thrift.ThriftHiveMetastore.createDatabase(ThriftHiveMetastore.java:1002)
2022-01-13T12:02:48.7204036Z 	at io.trino.plugin.hive.metastore.thrift.BridgingHiveMetastore.createDatabase(BridgingHiveMetastore.java:164)
2022-01-13T12:02:48.7207423Z 	at io.trino.plugin.hive.HiveQueryRunner$Builder.populateData(HiveQueryRunner.java:211)
2022-01-13T12:02:48.7209512Z 	at io.trino.plugin.hive.HiveQueryRunner$Builder.build(HiveQueryRunner.java:197)
2022-01-13T12:02:48.7211394Z 	at io.trino.plugin.hive.s3.S3HiveQueryRunner$Builder.build(S3HiveQueryRunner.java:160)
2022-01-13T12:02:48.7213475Z 	at io.trino.plugin.hive.s3.S3HiveQueryRunner.create(S3HiveQueryRunner.java:51)
2022-01-13T12:02:48.7216888Z 	at io.trino.plugin.hive.BaseTestHiveInsertOverwrite.createQueryRunner(BaseTestHiveInsertOverwrite.java:58)
2022-01-13T12:02:48.7222384Z 	at io.trino.testing.AbstractTestQueryFramework.init(AbstractTestQueryFramework.java:83)
2022-01-13T12:02:48.7225068Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2022-01-13T12:02:48.7228013Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2022-01-13T12:02:48.7231166Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2022-01-13T12:02:48.7234460Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2022-01-13T12:02:48.7237726Z 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2022-01-13T12:02:48.7240811Z 	at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:515)
2022-01-13T12:02:48.7242895Z 	at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:217)
2022-01-13T12:02:48.7245184Z 	at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:144)
2022-01-13T12:02:48.7247779Z 	at org.testng.internal.TestMethodWorker.invokeBeforeClassMethods(TestMethodWorker.java:169)
2022-01-13T12:02:48.7250437Z 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:108)
2022-01-13T12:02:48.7252695Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2022-01-13T12:02:48.7255393Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2022-01-13T12:02:48.7256912Z 	at java.base/java.lang.Thread.run(Thread.java:829)
2022-01-13T12:02:48.7257448Z 

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

@findepi
Copy link
Member

findepi commented May 23, 2022

I think the conclusion was this is most likely caused by a timeout + retry.

@aczajkowski @hashhar @findinpath has this been addressed with a test config change, or something like this?

@aczajkowski
Copy link
Member

@findepi Yes, some time ago we closed similar ticket #10772 in which this exact issue was solved by test config change #11592. Exactlly metastore read timeout.

@findepi
Copy link
Member

findepi commented May 23, 2022

The BaseTestHiveOnDataLake changed in #11592 is a successor of TestHive3InsertOverwrite mentioned here. Closing.

@findepi findepi closed this as completed May 23, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Development

Successfully merging a pull request may close this issue.

5 participants