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.

Sign up for GitHub

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

Jump to bottom

Flaky TestHiveTransactionalTable.testReadFullAcid #3635

Closed
ebyhr opened this issue May 6, 2020 · 8 comments
Closed

Flaky TestHiveTransactionalTable.testReadFullAcid #3635

ebyhr opened this issue May 6, 2020 · 8 comments
Labels
bug Something isn't working

Comments

@ebyhr
Copy link
Member

ebyhr commented May 6, 2020 

2020-05-05T17:49:52.2816759Z tests               | 2020-05-05 23:34:52 INFO: FAILURE     /    io.prestosql.tests.hive.TestHiveTransactionalTable.testReadFullAcid (Groups: storage_formats, hive_transactional) took 1 minutes and 29 seconds
2020-05-05T17:49:52.2846181Z tests               | 2020-05-05 23:34:52 SEVERE: Failure cause:
2020-05-05T17:49:52.2847236Z tests               | io.prestosql.tempto.query.QueryExecutionException: java.sql.SQLException: Query failed (#20200505_174951_00126_e9gni): File hdfs://hadoop-master:9000/user/hive/warehouse/test_full_acid_table_read/part_col=2/delta_0000002_0000003 does not exist.
2020-05-05T17:49:52.2847726Z tests               | 	at io.prestosql.tempto.query.JdbcQueryExecutor.execute(JdbcQueryExecutor.java:114)
2020-05-05T17:49:52.2848050Z tests               | 	at io.prestosql.tempto.query.JdbcQueryExecutor.executeQuery(JdbcQueryExecutor.java:82)
2020-05-05T17:49:52.2848501Z tests               | 	at io.prestosql.tempto.query.QueryExecutor.query(QueryExecutor.java:57)
2020-05-05T17:49:52.2848802Z tests               | 	at io.prestosql.tests.hive.TestHiveTransactionalTable.testReadFullAcid(TestHiveTransactionalTable.java:81)
2020-05-05T17:49:52.2849171Z tests               | 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-05-05T17:49:52.2849555Z tests               | 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-05-05T17:49:52.2849824Z tests               | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-05-05T17:49:52.2850112Z tests               | 	at java.lang.reflect.Method.invoke(Method.java:498)
2020-05-05T17:49:52.2850483Z tests               | 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2020-05-05T17:49:52.2851092Z tests               | 	at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:54)
2020-05-05T17:49:52.2851664Z tests               | 	at org.testng.internal.InvokeMethodRunnable.run(InvokeMethodRunnable.java:44)
2020-05-05T17:49:52.2851946Z tests               | 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
2020-05-05T17:49:52.2852276Z tests               | 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
2020-05-05T17:49:52.2852635Z tests               | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2020-05-05T17:49:52.2852942Z tests               | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-05-05T17:49:52.2853271Z tests               | 	at java.lang.Thread.run(Thread.java:748)
2020-05-05T17:49:52.2854402Z tests               | Caused by: java.sql.SQLException: Query failed (#20200505_174951_00126_e9gni): File hdfs://hadoop-master:9000/user/hive/warehouse/test_full_acid_table_read/part_col=2/delta_0000002_0000003 does not exist.
2020-05-05T17:49:52.2854842Z tests               | 	at io.prestosql.jdbc.PrestoResultSet.resultsException(PrestoResultSet.java:1894)
2020-05-05T17:49:52.2855787Z tests               | 	at io.prestosql.jdbc.PrestoResultSet$ResultsPageIterator.computeNext(PrestoResultSet.java:1883)
2020-05-05T17:49:52.2856151Z tests               | 	at io.prestosql.jdbc.PrestoResultSet$ResultsPageIterator.computeNext(PrestoResultSet.java:1843)
2020-05-05T17:49:52.2856410Z tests               | 	at io.prestosql.jdbc.$internal.guava.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
2020-05-05T17:49:52.2856671Z tests               | 	at io.prestosql.jdbc.$internal.guava.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
2020-05-05T17:49:52.2856907Z tests               | 	at java.util.Spliterators$IteratorSpliterator.tryAdvance(Spliterators.java:1811)
2020-05-05T17:49:52.2857183Z tests               | 	at java.util.stream.StreamSpliterators$WrappingSpliterator.lambda$initPartialTraversalState$0(StreamSpliterators.java:295)
2020-05-05T17:49:52.2857445Z tests               | 	at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(StreamSpliterators.java:207)
2020-05-05T17:49:52.2857709Z tests               | 	at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(StreamSpliterators.java:162)
2020-05-05T17:49:52.2857971Z tests               | 	at java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(StreamSpliterators.java:301)
2020-05-05T17:49:52.2858225Z tests               | 	at java.util.Spliterators$1Adapter.hasNext(Spliterators.java:681)
2020-05-05T17:49:52.2858481Z tests               | 	at io.prestosql.jdbc.PrestoResultSet$AsyncIterator.lambda$new$0(PrestoResultSet.java:1785)
2020-05-05T17:49:52.2858901Z tests               | 	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
2020-05-05T17:49:52.2859158Z tests               | 	... 3 more
2020-05-05T17:49:52.2859846Z tests               | Caused by: io.prestosql.spi.PrestoException: File hdfs://hadoop-master:9000/user/hive/warehouse/test_full_acid_table_read/part_col=2/delta_0000002_0000003 does not exist.
2020-05-05T17:49:52.2860188Z tests               | 	at io.prestosql.plugin.hive.BackgroundHiveSplitLoader$HiveSplitLoaderTask.process(BackgroundHiveSplitLoader.java:220)
2020-05-05T17:49:52.2860542Z tests               | 	at io.prestosql.plugin.hive.util.ResumableTasks$1.run(ResumableTasks.java:38)
2020-05-05T17:49:52.2860810Z tests               | 	at io.prestosql.$gen.Presto_00fc080____20200505_173519_2.run(Unknown Source)
2020-05-05T17:49:52.2861061Z tests               | 	at io.airlift.concurrent.BoundedExecutor.drainQueue(BoundedExecutor.java:78)
2020-05-05T17:49:52.2861317Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-05-05T17:49:52.2861734Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-05-05T17:49:52.2861983Z tests               | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-05-05T17:49:52.2862981Z tests               | Caused by: java.io.FileNotFoundException: File hdfs://hadoop-master:9000/user/hive/warehouse/test_full_acid_table_read/part_col=2/delta_0000002_0000003 does not exist.
2020-05-05T17:49:52.2863313Z tests               | 	at org.apache.hadoop.hdfs.DistributedFileSystem.listStatusInternal(DistributedFileSystem.java:1058)
2020-05-05T17:49:52.2863576Z tests               | 	at org.apache.hadoop.hdfs.DistributedFileSystem.access$1000(DistributedFileSystem.java:131)
2020-05-05T17:49:52.2863832Z tests               | 	at org.apache.hadoop.hdfs.DistributedFileSystem$24.doCall(DistributedFileSystem.java:1118)
2020-05-05T17:49:52.2864085Z tests               | 	at org.apache.hadoop.hdfs.DistributedFileSystem$24.doCall(DistributedFileSystem.java:1115)
2020-05-05T17:49:52.2864328Z tests               | 	at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81)
2020-05-05T17:49:52.2864588Z tests               | 	at org.apache.hadoop.hdfs.DistributedFileSystem.listStatus(DistributedFileSystem.java:1125)
2020-05-05T17:49:52.2864943Z tests               | 	at org.apache.hadoop.fs.FilterFileSystem.listStatus(FilterFileSystem.java:270)
2020-05-05T17:49:52.2865228Z tests               | 	at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:1868)
2020-05-05T17:49:52.2865478Z tests               | 	at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:1953)
2020-05-05T17:49:52.2865896Z tests               | 	at org.apache.hadoop.hive.ql.io.AcidUtils$MetaDataFile.chooseFile(AcidUtils.java:1671)
2020-05-05T17:49:52.2866137Z tests               | 	at org.apache.hadoop.hive.ql.io.AcidUtils$MetaDataFile.isRawFormat(AcidUtils.java:1681)
2020-05-05T17:49:52.2866361Z tests               | 	at org.apache.hadoop.hive.ql.io.AcidUtils.parsedDelta(AcidUtils.java:841)
2020-05-05T17:49:52.2866611Z tests               | 	at org.apache.hadoop.hive.ql.io.AcidUtils.parseDelta(AcidUtils.java:829)
2020-05-05T17:49:52.2866856Z tests               | 	at org.apache.hadoop.hive.ql.io.AcidUtils.getChildState(AcidUtils.java:1151)
2020-05-05T17:49:52.2867467Z tests               | 	at org.apache.hadoop.hive.ql.io.AcidUtils.getAcidState(AcidUtils.java:956)
2020-05-05T17:49:52.2879339Z tests               | 	at org.apache.hadoop.hive.ql.io.AcidUtils.getAcidState(AcidUtils.java:915)
2020-05-05T17:49:52.2879779Z tests               | 	at io.prestosql.plugin.hive.BackgroundHiveSplitLoader.lambda$loadPartition$3(BackgroundHiveSplitLoader.java:415)
2020-05-05T17:49:52.2880126Z tests               | 	at io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.lambda$executeActionInDoAs$0(UserGroupInformationUtils.java:29)
2020-05-05T17:49:52.2880392Z tests               | 	at java.base/java.security.AccessController.doPrivileged(Native Method)
2020-05-05T17:49:52.2880724Z tests               | 	at java.base/javax.security.auth.Subject.doAs(Subject.java:361)
2020-05-05T17:49:52.2881029Z tests               | 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1710)
2020-05-05T17:49:52.2881349Z tests               | 	at io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.executeActionInDoAs(UserGroupInformationUtils.java:27)
2020-05-05T17:49:52.2905147Z tests               | 	at io.prestosql.plugin.hive.authentication.ImpersonatingHdfsAuthentication.doAs(ImpersonatingHdfsAuthentication.java:39)
2020-05-05T17:49:52.2905499Z tests               | 	at io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-05-05T17:49:52.2905773Z tests               | 	at io.prestosql.plugin.hive.BackgroundHiveSplitLoader.loadPartition(BackgroundHiveSplitLoader.java:415)
2020-05-05T17:49:52.2906034Z tests               | 	at io.prestosql.plugin.hive.BackgroundHiveSplitLoader.loadSplits(BackgroundHiveSplitLoader.java:287)
2020-05-05T17:49:52.2906522Z tests               | 	at io.prestosql.plugin.hive.BackgroundHiveSplitLoader.access$300(BackgroundHiveSplitLoader.java:107)
2020-05-05T17:49:52.2906796Z tests               | 	at io.prestosql.plugin.hive.BackgroundHiveSplitLoader$HiveSplitLoaderTask.process(BackgroundHiveSplitLoader.java:216)
2020-05-05T17:49:52.2907047Z tests               | 	... 6 more

https://github.com/prestosql/presto/actions/runs/96099095
https://github.com/prestosql/presto/actions/runs/96341740
@ebyhr ebyhr added bug Something isn't working test labels May 6, 2020
@ebyhr ebyhr mentioned this issue May 6, 2020
Merged
@findepi
Copy link
Member

findepi commented May 6, 2020

Could it be compaction in the background?
Our transaction read lock should prevent the files from disappearing while Presto query is running.

@findepi findepi removed the test label May 6, 2020
@findepi
Copy link
Member

findepi commented May 6, 2020

I removed the test label, as this looks more likely as a product problem to me.

@ebyhr ebyhr mentioned this issue May 8, 2020
Merged
@sopel39
Copy link
Member

sopel39 commented Jun 2, 2020

another one: https://github.com/prestosql/presto/pull/3874/checks?check_run_id=731788352

@findepi findepi mentioned this issue Jun 6, 2020
Merged
@findepi
Copy link
Member

findepi commented Jun 6, 2020

https://github.com/prestosql/presto/runs/745458091

@losipiuk losipiuk mentioned this issue Jun 19, 2020
Closed
@kokosing kokosing mentioned this issue Jul 7, 2020
Merged
@hashhar
Copy link
Member

hashhar commented Sep 21, 2021

@losipiuk Could the cause be same as #8899? The test creates an ACID unbucketed table which we didn't detect correctly as being ACID before your change.

@findepi
Copy link
Member

findepi commented Oct 7, 2022

Let's hope the issue is obsolete. We haven't seen any comments here for past year.

@findepi findepi closed this as completed Oct 7, 2022
@sopel39
Copy link
Member

sopel39 commented Dec 5, 2023

https://github.com/trinodb/trino/actions/runs/7100427012/job/19327171079?pr=20023

tests               | 2023-12-05 18:45:36 INFO: Test io.trino.tests.product.hive.TestHiveTransactionalTable.testReadFullAcid took 1.15m
tests               | 2023-12-05 18:45:36 INFO: FAILURE     /    io.trino.tests.product.hive.TestHiveTransactionalTable.testReadFullAcid (Groups: hive_transactional) took 1 minutes and 8 seconds
tests               | 2023-12-05 18:45:36 SEVERE: Failure cause:
tests               | io.trino.tempto.query.QueryExecutionException: java.sql.SQLException: Query failed (#20231205_130036_00548_fxg69): Found file in sub-directory of ACID directory: hdfs://hadoop-master:9000/user/hive/warehouse/test_read_full_acid_false_none_lkve9nybnn/delete_delta_0000002_0000005/delete_delta_0000002_0000005/bucket_00000
tests               | 	at io.trino.tempto.query.JdbcQueryExecutor.execute(JdbcQueryExecutor.java:119)
tests               | 	at io.trino.tempto.query.JdbcQueryExecutor.executeQuery(JdbcQueryExecutor.java:84)
tests               | 	at io.trino.tests.product.utils.QueryExecutors$1.lambda$executeQuery$0(QueryExecutors.java:54)
tests               | 	at dev.failsafe.Functions.lambda$toCtxSupplier$11(Functions.java:243)
tests               | 	at dev.failsafe.Functions.lambda$get$0(Functions.java:46)
tests               | 	at dev.failsafe.internal.RetryPolicyExecutor.lambda$apply$0(RetryPolicyExecutor.java:74)
tests               | 	at dev.failsafe.SyncExecutionImpl.executeSync(SyncExecutionImpl.java:187)
tests               | 	at dev.failsafe.FailsafeExecutor.call(FailsafeExecutor.java:376)
tests               | 	at dev.failsafe.FailsafeExecutor.get(FailsafeExecutor.java:112)
tests               | 	at io.trino.tests.product.utils.QueryExecutors$1.executeQuery(QueryExecutors.java:54)
tests               | 	at io.trino.tests.product.hive.TestHiveTransactionalTable.doTestReadFullAcid(TestHiveTransactionalTable.java:182)
tests               | 	at io.trino.tests.product.hive.TestHiveTransactionalTable.testReadFullAcid(TestHiveTransactionalTable.java:104)
tests               | 	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
tests               | 	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
tests               | 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
tests               | 	at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:54)

@sopel39 sopel39 reopened this Dec 5, 2023
This was referenced Dec 7, 2023
Merged
Merged
@findepi
Copy link
Member

findepi commented Dec 19, 2023

re-closing in favor of #16315

cc @sopel39

@findepi findepi closed this as completed Dec 19, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Milestone
No milestone
Development

No branches or pull requests
4 participants
@findepi @sopel39 @ebyhr @hashhar