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 test TestIcebergCreateTable.testCreateTable #4864

Closed
findepi opened this issue Aug 17, 2020 · 5 comments
Closed

Flaky test TestIcebergCreateTable.testCreateTable #4864

findepi opened this issue Aug 17, 2020 · 5 comments
Labels
bug Something isn't working

Comments

@findepi
Copy link
Member

findepi commented Aug 17, 2020

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

2020-08-17T17:01:22.1374484Z tests               | 2020-08-17 22:46:22 INFO: [2 of 79] io.prestosql.tests.iceberg.TestIcebergCreateTable.testCreateTable (Groups: storage_formats, iceberg)
2020-08-17T17:01:23.7409762Z presto-master       | 2020-08-17T22:46:23.739+0545	INFO	dispatcher-query-0	io.prestosql.event.QueryMonitor	TIMELINE: Query 20200817_170122_00004_i3ec2 :: Transaction:[22a4da64-71e4-470d-ae3b-889c066d49d8] :: elapsed 1574ms :: planning 0ms :: waiting 0ms :: scheduling 1574ms :: running 0ms :: finishing 1574ms :: begin 2020-08-17T22:46:22.155+05:45 :: end 2020-08-17T22:46:23.729+05:45
2020-08-17T17:01:23.9066268Z presto-master       | 2020-08-17T22:46:23.905+0545	INFO	dispatcher-query-1	io.prestosql.event.QueryMonitor	TIMELINE: Query 20200817_170123_00005_i3ec2 :: Transaction:[94891482-032a-4adc-82bd-59531ce4bcad] :: elapsed 148ms :: planning 0ms :: waiting 0ms :: scheduling 148ms :: running 0ms :: finishing 148ms :: begin 2020-08-17T22:46:23.750+05:45 :: end 2020-08-17T22:46:23.898+05:45
2020-08-17T17:01:25.5700660Z presto-master       | 2020-08-17T22:46:25.569+0545	INFO	dispatcher-query-2	org.apache.iceberg.SnapshotProducer	Committed snapshot 7647515295446047994 (FastAppend)
2020-08-17T17:01:26.0086624Z presto-master       | 2020-08-17T22:46:26.007+0545	INFO	dispatcher-query-1	io.prestosql.event.QueryMonitor	TIMELINE: Query 20200817_170123_00006_i3ec2 :: Transaction:[80b4198d-4581-4567-9ef1-ee5e173a1fc8] :: elapsed 2077ms :: planning 0ms :: waiting 0ms :: scheduling 2077ms :: running 0ms :: finishing 2077ms :: begin 2020-08-17T22:46:23.919+05:45 :: end 2020-08-17T22:46:25.996+05:45
2020-08-17T17:01:26.9724270Z presto-master       | 2020-08-17T22:46:26.969+0545	WARN	Finalizer	org.apache.iceberg.hadoop.HadoopStreams	Unclosed input stream created by:
2020-08-17T17:01:26.9772691Z presto-master       | 	org.apache.iceberg.hadoop.HadoopStreams$HadoopSeekableInputStream.<init>(HadoopStreams.java:80)
2020-08-17T17:01:26.9773294Z presto-master       | 	org.apache.iceberg.hadoop.HadoopStreams.wrap(HadoopStreams.java:55)
2020-08-17T17:01:26.9773714Z presto-master       | 	org.apache.iceberg.hadoop.HadoopInputFile.newStream(HadoopInputFile.java:157)
2020-08-17T17:01:26.9866172Z presto-master       | 	io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.lambda$executeActionInDoAs$0(UserGroupInformationUtils.java:29)
2020-08-17T17:01:26.9867126Z presto-master       | 	java.base/java.security.AccessController.doPrivileged(Native Method)
2020-08-17T17:01:26.9867885Z presto-master       | 	java.base/javax.security.auth.Subject.doAs(Subject.java:361)
2020-08-17T17:01:26.9868647Z presto-master       | 	org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1710)
2020-08-17T17:01:26.9869474Z presto-master       | 	io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.executeActionInDoAs(UserGroupInformationUtils.java:27)
2020-08-17T17:01:26.9870305Z presto-master       | 	io.prestosql.plugin.hive.authentication.ImpersonatingHdfsAuthentication.doAs(ImpersonatingHdfsAuthentication.java:39)
2020-08-17T17:01:26.9871051Z presto-master       | 	io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-08-17T17:01:26.9871797Z presto-master       | 	io.prestosql.plugin.iceberg.HdfsInputFile.newStream(HdfsInputFile.java:59)
2020-08-17T17:01:26.9872550Z presto-master       | 	org.apache.iceberg.parquet.ParquetIO$ParquetInputFile.newStream(ParquetIO.java:181)
2020-08-17T17:01:26.9873294Z presto-master       | 	org.apache.parquet.hadoop.ParquetFileReader.<init>(ParquetFileReader.java:709)
2020-08-17T17:01:26.9874039Z presto-master       | 	org.apache.parquet.hadoop.ParquetFileReader.open(ParquetFileReader.java:597)
2020-08-17T17:01:26.9874782Z presto-master       | 	org.apache.iceberg.parquet.ParquetUtil.fileMetrics(ParquetUtil.java:73)
2020-08-17T17:01:26.9875579Z presto-master       | 	io.prestosql.plugin.iceberg.IcebergParquetFileWriter.lambda$getMetrics$0(IcebergParquetFileWriter.java:72)
2020-08-17T17:01:26.9876386Z presto-master       | 	io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.lambda$executeActionInDoAs$0(UserGroupInformationUtils.java:29)
2020-08-17T17:01:26.9877267Z presto-master       | 	java.base/java.security.AccessController.doPrivileged(Native Method)
2020-08-17T17:01:26.9877964Z presto-master       | 	java.base/javax.security.auth.Subject.doAs(Subject.java:361)
2020-08-17T17:01:26.9879591Z presto-master       | 	org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1710)
2020-08-17T17:01:26.9880615Z presto-master       | 	io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.executeActionInDoAs(UserGroupInformationUtils.java:27)
2020-08-17T17:01:26.9881636Z presto-master       | 	io.prestosql.plugin.hive.authentication.ImpersonatingHdfsAuthentication.doAs(ImpersonatingHdfsAuthentication.java:39)
2020-08-17T17:01:26.9882255Z presto-master       | 	io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-08-17T17:01:26.9882880Z presto-master       | 	io.prestosql.plugin.iceberg.IcebergParquetFileWriter.getMetrics(IcebergParquetFileWriter.java:72)
2020-08-17T17:01:26.9883474Z presto-master       | 	io.prestosql.plugin.iceberg.IcebergPageSink.finish(IcebergPageSink.java:165)
2020-08-17T17:01:26.9884139Z presto-master       | 	io.prestosql.plugin.base.classloader.ClassLoaderSafeConnectorPageSink.finish(ClassLoaderSafeConnectorPageSink.java:77)
2020-08-17T17:01:26.9884743Z presto-master       | 	io.prestosql.operator.TableWriterOperator.finish(TableWriterOperator.java:203)
2020-08-17T17:01:26.9885324Z presto-master       | 	io.prestosql.operator.Driver.processInternal(Driver.java:397)
2020-08-17T17:01:26.9885905Z presto-master       | 	io.prestosql.operator.Driver.lambda$processFor$8(Driver.java:283)
2020-08-17T17:01:26.9886717Z presto-master       | 	io.prestosql.operator.Driver.tryWithLock(Driver.java:675)
2020-08-17T17:01:26.9887431Z presto-master       | 	io.prestosql.operator.Driver.processFor(Driver.java:276)
2020-08-17T17:01:26.9888055Z presto-master       | 	io.prestosql.execution.SqlTaskExecution$DriverSplitRunner.processFor(SqlTaskExecution.java:1076)
2020-08-17T17:01:26.9888670Z presto-master       | 	io.prestosql.execution.executor.PrioritizedSplitRunner.process(PrioritizedSplitRunner.java:163)
2020-08-17T17:01:26.9889269Z presto-master       | 	io.prestosql.execution.executor.TaskExecutor$TaskRunner.run(TaskExecutor.java:484)
2020-08-17T17:01:26.9889867Z presto-master       | 	io.prestosql.$gen.Presto_1fc4a39____20200817_165912_2.run(Unknown Source)
2020-08-17T17:01:26.9890476Z presto-master       | 	java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-08-17T17:01:26.9891064Z presto-master       | 	java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-08-17T17:01:26.9891640Z presto-master       | 	java.base/java.lang.Thread.run(Thread.java:834)
2020-08-17T17:01:27.0126897Z presto-master       | 2020-08-17T22:46:27.008+0545	ERROR	remote-task-callback-0	io.prestosql.execution.StageStateMachine	Stage 20200817_170126_00007_i3ec2.1 failed
2020-08-17T17:01:27.0127756Z presto-master       | org.apache.iceberg.exceptions.RuntimeIOException: Failed to read footer of file: io.prestosql.plugin.iceberg.HdfsInputFile@2a81330f
2020-08-17T17:01:27.0128394Z presto-master       | 	at org.apache.iceberg.parquet.ParquetUtil.fileMetrics(ParquetUtil.java:76)
2020-08-17T17:01:27.0129036Z presto-master       | 	at io.prestosql.plugin.iceberg.IcebergParquetFileWriter.lambda$getMetrics$0(IcebergParquetFileWriter.java:72)
2020-08-17T17:01:27.0129575Z presto-master       | 	at io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.lambda$executeActionInDoAs$0(UserGroupInformationUtils.java:29)
2020-08-17T17:01:27.0130219Z presto-master       | 	at java.base/java.security.AccessController.doPrivileged(Native Method)
2020-08-17T17:01:27.0130828Z presto-master       | 	at java.base/javax.security.auth.Subject.doAs(Subject.java:361)
2020-08-17T17:01:27.0131273Z presto-master       | 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1710)
2020-08-17T17:01:27.0131965Z presto-master       | 	at io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.executeActionInDoAs(UserGroupInformationUtils.java:27)
2020-08-17T17:01:27.0132643Z presto-master       | 	at io.prestosql.plugin.hive.authentication.ImpersonatingHdfsAuthentication.doAs(ImpersonatingHdfsAuthentication.java:39)
2020-08-17T17:01:27.0133237Z presto-master       | 	at io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-08-17T17:01:27.0133706Z presto-master       | 	at io.prestosql.plugin.iceberg.IcebergParquetFileWriter.getMetrics(IcebergParquetFileWriter.java:72)
2020-08-17T17:01:27.0134347Z presto-master       | 	at io.prestosql.plugin.iceberg.IcebergPageSink.finish(IcebergPageSink.java:165)
2020-08-17T17:01:27.0134992Z presto-master       | 	at io.prestosql.plugin.base.classloader.ClassLoaderSafeConnectorPageSink.finish(ClassLoaderSafeConnectorPageSink.java:77)
2020-08-17T17:01:27.0135613Z presto-master       | 	at io.prestosql.operator.TableWriterOperator.finish(TableWriterOperator.java:203)
2020-08-17T17:01:27.0136039Z presto-master       | 	at io.prestosql.operator.Driver.processInternal(Driver.java:397)
2020-08-17T17:01:27.0136692Z presto-master       | 	at io.prestosql.operator.Driver.lambda$processFor$8(Driver.java:283)
2020-08-17T17:01:27.0137257Z presto-master       | 	at io.prestosql.operator.Driver.tryWithLock(Driver.java:675)
2020-08-17T17:01:27.0137674Z presto-master       | 	at io.prestosql.operator.Driver.processFor(Driver.java:276)
2020-08-17T17:01:27.0138317Z presto-master       | 	at io.prestosql.execution.SqlTaskExecution$DriverSplitRunner.processFor(SqlTaskExecution.java:1076)
2020-08-17T17:01:27.0139181Z presto-master       | 	at io.prestosql.execution.executor.PrioritizedSplitRunner.process(PrioritizedSplitRunner.java:163)
2020-08-17T17:01:27.0139989Z presto-master       | 	at io.prestosql.execution.executor.TaskExecutor$TaskRunner.run(TaskExecutor.java:484)
2020-08-17T17:01:27.0140436Z presto-master       | 	at io.prestosql.$gen.Presto_1fc4a39____20200817_165912_2.run(Unknown Source)
2020-08-17T17:01:27.0140845Z presto-master       | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-08-17T17:01:27.0141525Z presto-master       | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-08-17T17:01:27.0141885Z presto-master       | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-08-17T17:01:27.0142236Z presto-master       | Caused by: java.io.IOException: Stream is closed!
2020-08-17T17:01:27.0142617Z presto-master       | 	at org.apache.hadoop.hdfs.DFSInputStream.seek(DFSInputStream.java:1453)
2020-08-17T17:01:27.0143012Z presto-master       | 	at org.apache.hadoop.fs.FSDataInputStream.seek(FSDataInputStream.java:65)
2020-08-17T17:01:27.0143603Z presto-master       | 	at org.apache.hadoop.fs.FSDataInputStream.seek(FSDataInputStream.java:65)
2020-08-17T17:01:27.0144064Z presto-master       | 	at org.apache.parquet.hadoop.util.H2SeekableInputStream.seek(H2SeekableInputStream.java:60)
2020-08-17T17:01:27.0144466Z presto-master       | 	at org.apache.parquet.hadoop.ParquetFileReader.readFooter(ParquetFileReader.java:526)
2020-08-17T17:01:27.0144862Z presto-master       | 	at org.apache.parquet.hadoop.ParquetFileReader.<init>(ParquetFileReader.java:712)
2020-08-17T17:01:27.0145257Z presto-master       | 	at org.apache.parquet.hadoop.ParquetFileReader.open(ParquetFileReader.java:597)
2020-08-17T17:01:27.0145639Z presto-master       | 	at org.apache.iceberg.parquet.ParquetUtil.fileMetrics(ParquetUtil.java:73)
2020-08-17T17:01:27.0145959Z presto-master       | 	... 23 more
2020-08-17T17:01:27.0146219Z presto-master       | 
2020-08-17T17:01:27.0146493Z presto-master       | 
2020-08-17T17:01:27.0818043Z tests               | 2020-08-17 22:46:27 INFO: FAILURE     /    io.prestosql.tests.iceberg.TestIcebergCreateTable.testCreateTable (Groups: storage_formats, iceberg) took 4.9 seconds
2020-08-17T17:01:27.0966329Z tests               | 2020-08-17 22:46:27 SEVERE: Failure cause:
2020-08-17T17:01:27.0966571Z tests               | io.prestosql.tempto.query.QueryExecutionException: java.sql.SQLException: Query failed (#20200817_170126_00007_i3ec2): Failed to read footer of file: io.prestosql.plugin.iceberg.HdfsInputFile@2a81330f
2020-08-17T17:01:27.0966767Z tests               | 	at io.prestosql.tempto.query.JdbcQueryExecutor.execute(JdbcQueryExecutor.java:114)
2020-08-17T17:01:27.0966939Z tests               | 	at io.prestosql.tempto.query.JdbcQueryExecutor.executeQuery(JdbcQueryExecutor.java:82)
2020-08-17T17:01:27.0967113Z tests               | 	at io.prestosql.tests.iceberg.TestIcebergCreateTable.testCreateTable(TestIcebergCreateTable.java:36)
2020-08-17T17:01:27.0967305Z tests               | 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-08-17T17:01:27.0967485Z tests               | 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-08-17T17:01:27.0967660Z tests               | 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-08-17T17:01:27.0967824Z tests               | 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-08-17T17:01:27.0967992Z tests               | 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2020-08-17T17:01:27.0968133Z tests               | 	at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
2020-08-17T17:01:27.0968292Z tests               | 	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
2020-08-17T17:01:27.0968449Z tests               | 	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
2020-08-17T17:01:27.0968809Z tests               | 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
2020-08-17T17:01:27.0969080Z tests               | 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
2020-08-17T17:01:27.0969247Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-08-17T17:01:27.0969414Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-08-17T17:01:27.0969569Z tests               | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-08-17T17:01:27.0969753Z tests               | Caused by: java.sql.SQLException: Query failed (#20200817_170126_00007_i3ec2): Failed to read footer of file: io.prestosql.plugin.iceberg.HdfsInputFile@2a81330f
2020-08-17T17:01:27.0969940Z tests               | 	at io.prestosql.jdbc.AbstractPrestoResultSet.resultsException(AbstractPrestoResultSet.java:1757)
2020-08-17T17:01:27.0970114Z tests               | 	at io.prestosql.jdbc.PrestoResultSet$ResultsPageIterator.computeNext(PrestoResultSet.java:225)
2020-08-17T17:01:27.0970285Z tests               | 	at io.prestosql.jdbc.PrestoResultSet$ResultsPageIterator.computeNext(PrestoResultSet.java:185)
2020-08-17T17:01:27.0970454Z tests               | 	at io.prestosql.jdbc.$internal.guava.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
2020-08-17T17:01:27.0970623Z tests               | 	at io.prestosql.jdbc.$internal.guava.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
2020-08-17T17:01:27.0970769Z tests               | 	at java.base/java.util.Spliterators$IteratorSpliterator.tryAdvance(Spliterators.java:1811)
2020-08-17T17:01:27.0970946Z tests               | 	at java.base/java.util.stream.StreamSpliterators$WrappingSpliterator.lambda$initPartialTraversalState$0(StreamSpliterators.java:294)
2020-08-17T17:01:27.0971127Z tests               | 	at java.base/java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(StreamSpliterators.java:206)
2020-08-17T17:01:27.0971303Z tests               | 	at java.base/java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(StreamSpliterators.java:161)
2020-08-17T17:01:27.0971475Z tests               | 	at java.base/java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(StreamSpliterators.java:300)
2020-08-17T17:01:27.0971637Z tests               | 	at java.base/java.util.Spliterators$1Adapter.hasNext(Spliterators.java:681)
2020-08-17T17:01:27.0971802Z tests               | 	at io.prestosql.jdbc.PrestoResultSet$AsyncIterator.lambda$new$0(PrestoResultSet.java:131)
2020-08-17T17:01:27.0971965Z tests               | 	at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1736)
2020-08-17T17:01:27.0972109Z tests               | 	... 3 more
2020-08-17T17:01:27.0972279Z tests               | Caused by: org.apache.iceberg.exceptions.RuntimeIOException: Failed to read footer of file: io.prestosql.plugin.iceberg.HdfsInputFile@2a81330f
2020-08-17T17:01:27.0972456Z tests               | 	at org.apache.iceberg.parquet.ParquetUtil.fileMetrics(ParquetUtil.java:76)
2020-08-17T17:01:27.0972624Z tests               | 	at io.prestosql.plugin.iceberg.IcebergParquetFileWriter.lambda$getMetrics$0(IcebergParquetFileWriter.java:72)
2020-08-17T17:01:27.0972800Z tests               | 	at io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.lambda$executeActionInDoAs$0(UserGroupInformationUtils.java:29)
2020-08-17T17:01:27.0972969Z tests               | 	at java.base/java.security.AccessController.doPrivileged(Native Method)
2020-08-17T17:01:27.0973126Z tests               | 	at java.base/javax.security.auth.Subject.doAs(Subject.java:361)
2020-08-17T17:01:27.0973273Z tests               | 	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1710)
2020-08-17T17:01:27.0973525Z tests               | 	at io.prestosql.plugin.hive.authentication.UserGroupInformationUtils.executeActionInDoAs(UserGroupInformationUtils.java:27)
2020-08-17T17:01:27.0973773Z tests               | 	at io.prestosql.plugin.hive.authentication.ImpersonatingHdfsAuthentication.doAs(ImpersonatingHdfsAuthentication.java:39)
2020-08-17T17:01:27.0973941Z tests               | 	at io.prestosql.plugin.hive.HdfsEnvironment.doAs(HdfsEnvironment.java:89)
2020-08-17T17:01:27.0974108Z tests               | 	at io.prestosql.plugin.iceberg.IcebergParquetFileWriter.getMetrics(IcebergParquetFileWriter.java:72)
2020-08-17T17:01:27.0974273Z tests               | 	at io.prestosql.plugin.iceberg.IcebergPageSink.finish(IcebergPageSink.java:165)
2020-08-17T17:01:27.0974444Z tests               | 	at io.prestosql.plugin.base.classloader.ClassLoaderSafeConnectorPageSink.finish(ClassLoaderSafeConnectorPageSink.java:77)
2020-08-17T17:01:27.0974614Z tests               | 	at io.prestosql.operator.TableWriterOperator.finish(TableWriterOperator.java:203)
2020-08-17T17:01:27.0974774Z tests               | 	at io.prestosql.operator.Driver.processInternal(Driver.java:397)
2020-08-17T17:01:27.0974933Z tests               | 	at io.prestosql.operator.Driver.lambda$processFor$8(Driver.java:283)
2020-08-17T17:01:27.0975091Z tests               | 	at io.prestosql.operator.Driver.tryWithLock(Driver.java:675)
2020-08-17T17:01:27.0975245Z tests               | 	at io.prestosql.operator.Driver.processFor(Driver.java:276)
2020-08-17T17:01:27.0975391Z tests               | 	at io.prestosql.execution.SqlTaskExecution$DriverSplitRunner.processFor(SqlTaskExecution.java:1076)
2020-08-17T17:01:27.0975558Z tests               | 	at io.prestosql.execution.executor.PrioritizedSplitRunner.process(PrioritizedSplitRunner.java:163)
2020-08-17T17:01:27.0975724Z tests               | 	at io.prestosql.execution.executor.TaskExecutor$TaskRunner.run(TaskExecutor.java:484)
2020-08-17T17:01:27.0975883Z tests               | 	at io.prestosql.$gen.Presto_1fc4a39____20200817_165912_2.run(Unknown Source)
2020-08-17T17:01:27.0976051Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-08-17T17:01:27.0976227Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-08-17T17:01:27.0976382Z tests               | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-08-17T17:01:27.0976532Z tests               | Caused by: java.io.IOException: Stream is closed!
2020-08-17T17:01:27.0976691Z tests               | 	at org.apache.hadoop.hdfs.DFSInputStream.seek(DFSInputStream.java:1453)
2020-08-17T17:01:27.0976851Z tests               | 	at org.apache.hadoop.fs.FSDataInputStream.seek(FSDataInputStream.java:65)
2020-08-17T17:01:27.0977008Z tests               | 	at org.apache.hadoop.fs.FSDataInputStream.seek(FSDataInputStream.java:65)
2020-08-17T17:01:27.0977169Z tests               | 	at org.apache.parquet.hadoop.util.H2SeekableInputStream.seek(H2SeekableInputStream.java:60)
2020-08-17T17:01:27.0977324Z tests               | 	at org.apache.parquet.hadoop.ParquetFileReader.readFooter(ParquetFileReader.java:526)
2020-08-17T17:01:27.0977492Z tests               | 	at org.apache.parquet.hadoop.ParquetFileReader.<init>(ParquetFileReader.java:712)
2020-08-17T17:01:27.0977653Z tests               | 	at org.apache.parquet.hadoop.ParquetFileReader.open(ParquetFileReader.java:597)
2020-08-17T17:01:27.0977809Z tests               | 	at org.apache.iceberg.parquet.ParquetUtil.fileMetrics(ParquetUtil.java:73)
2020-08-17T17:01:27.0977952Z tests               | 	... 23 more
2020-08-17T17:01:27.0978078Z tests               | 
2020-08-17T17:01:27.1344163Z presto-master       | 2020-08-17T22:46:27.133+0545	INFO	dispatcher-query-3	io.prestosql.event.QueryMonitor	TIMELINE: Query 20200817_170126_00007_i3ec2 :: Transaction:[1be34943-91d6-4bb5-a2b6-fca79f493687] :: elapsed 971ms :: planning 110ms :: waiting 257ms :: scheduling 320ms :: running 28ms :: finishing 513ms :: begin 2020-08-17T22:46:26.044+05:45 :: end 2020-08-17T22:46:27.015+05:45
2020-08-17T17:01:27.7950957Z tests               | 2020-08-17 22:46:27 INFO: [3 of 79] io.prestosql.tests.iceberg.TestIcebergCreateTable.testCreateTableAsSelect (Groups: storage_formats, iceberg)
2020-08-17T17:01:28.0102958Z tests               | 2020-08-17 22:46:28 INFO: FAILURE     /    io.prestosql.tests.iceberg.TestIcebergCreateTable.testCreateTableAsSelect (Groups: storage_formats, iceberg) took 0.2 seconds
2020-08-17T17:01:28.0130002Z tests               | 2020-08-17 22:46:28 SEVERE: Failure cause:
2020-08-17T17:01:28.0130880Z tests               | io.prestosql.tempto.query.QueryExecutionException: java.sql.SQLException: Query failed (#20200817_170127_00008_i3ec2): line 1:1: Schema 'iceberg.iceberg' already exists
2020-08-17T17:01:28.0131277Z tests               | 	at io.prestosql.tempto.query.JdbcQueryExecutor.execute(JdbcQueryExecutor.java:114)
2020-08-17T17:01:28.0131447Z tests               | 	at io.prestosql.tempto.query.JdbcQueryExecutor.executeQuery(JdbcQueryExecutor.java:82)
2020-08-17T17:01:28.0131645Z tests               | 	at io.prestosql.tests.iceberg.TestIcebergCreateTable.testCreateTableAsSelect(TestIcebergCreateTable.java:53)
2020-08-17T17:01:28.0131960Z tests               | 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-08-17T17:01:28.0132138Z tests               | 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-08-17T17:01:28.0132310Z tests               | 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-08-17T17:01:28.0132471Z tests               | 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2020-08-17T17:01:28.0132780Z tests               | 	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
2020-08-17T17:01:28.0132944Z tests               | 	at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
2020-08-17T17:01:28.0133099Z tests               | 	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
2020-08-17T17:01:28.0133260Z tests               | 	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
2020-08-17T17:01:28.0133540Z tests               | 	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
2020-08-17T17:01:28.0133706Z tests               | 	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
2020-08-17T17:01:28.0133869Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-08-17T17:01:28.0134035Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-08-17T17:01:28.0134319Z tests               | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-08-17T17:01:28.0135005Z tests               | Caused by: java.sql.SQLException: Query failed (#20200817_170127_00008_i3ec2): line 1:1: Schema 'iceberg.iceberg' already exists
2020-08-17T17:01:28.0135222Z tests               | 	at io.prestosql.jdbc.AbstractPrestoResultSet.resultsException(AbstractPrestoResultSet.java:1757)
2020-08-17T17:01:28.0135391Z tests               | 	at io.prestosql.jdbc.PrestoResultSet.getColumns(PrestoResultSet.java:249)
2020-08-17T17:01:28.0135550Z tests               | 	at io.prestosql.jdbc.PrestoResultSet.create(PrestoResultSet.java:52)
2020-08-17T17:01:28.0135841Z tests               | 	at io.prestosql.jdbc.PrestoStatement.internalExecute(PrestoStatement.java:249)
2020-08-17T17:01:28.0136006Z tests               | 	at io.prestosql.jdbc.PrestoStatement.execute(PrestoStatement.java:227)
2020-08-17T17:01:28.0136171Z tests               | 	at io.prestosql.tempto.query.JdbcQueryExecutor.executeQueryNoParams(JdbcQueryExecutor.java:122)
2020-08-17T17:01:28.0136317Z tests               | 	at io.prestosql.tempto.query.JdbcQueryExecutor.execute(JdbcQueryExecutor.java:107)
2020-08-17T17:01:28.0136588Z tests               | 	... 15 more
2020-08-17T17:01:28.0137420Z tests               | Caused by: io.prestosql.spi.PrestoException: line 1:1: Schema 'iceberg.iceberg' already exists
2020-08-17T17:01:28.0137730Z tests               | 	at io.prestosql.sql.analyzer.SemanticExceptions.semanticException(SemanticExceptions.java:48)
2020-08-17T17:01:28.0137893Z tests               | 	at io.prestosql.sql.analyzer.SemanticExceptions.semanticException(SemanticExceptions.java:43)
2020-08-17T17:01:28.0138200Z tests               | 	at io.prestosql.execution.CreateSchemaTask.internalExecute(CreateSchemaTask.java:78)
2020-08-17T17:01:28.0138374Z tests               | 	at io.prestosql.execution.CreateSchemaTask.execute(CreateSchemaTask.java:64)
2020-08-17T17:01:28.0138530Z tests               | 	at io.prestosql.execution.CreateSchemaTask.execute(CreateSchemaTask.java:46)
2020-08-17T17:01:28.0138691Z tests               | 	at io.prestosql.execution.DataDefinitionExecution.start(DataDefinitionExecution.java:167)
2020-08-17T17:01:28.0138967Z tests               | 	at io.prestosql.execution.SqlQueryManager.createQuery(SqlQueryManager.java:245)
2020-08-17T17:01:28.0139146Z tests               | 	at io.prestosql.dispatcher.LocalDispatchQuery.lambda$startExecution$7(LocalDispatchQuery.java:132)
2020-08-17T17:01:28.0139308Z tests               | 	at io.prestosql.$gen.Presto_1fc4a39____20200817_165912_2.run(Unknown Source)
2020-08-17T17:01:28.0139473Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-08-17T17:01:28.0139743Z tests               | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-08-17T17:01:28.0139913Z tests               | 	at java.base/java.lang.Thread.run(Thread.java:834)
2020-08-17T17:01:28.0140048Z tests               |
@findepi findepi mentioned this issue Aug 17, 2020
Merged
@ebyhr ebyhr mentioned this issue Aug 23, 2020
Closed
@findepi findepi mentioned this issue Nov 9, 2020
Merged
@findepi
Copy link
Member Author

findepi commented Nov 9, 2020

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

@findepi
Copy link
Member Author

findepi commented Nov 9, 2020

cc @vrozov @djsstarburst

@findepi findepi mentioned this issue Nov 9, 2020
Merged
@findepi findepi added the bug Something isn't working label Nov 9, 2020
@vrozov
Copy link
Contributor

vrozov commented Nov 9, 2020

Looks like a race condition in iceberg to me.

@kokosing kokosing mentioned this issue Nov 16, 2020
Merged
This was referenced Nov 16, 2020
Merged
Merged
Merged
@findepi
Copy link
Member Author

findepi commented Nov 21, 2020

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

@findepi findepi mentioned this issue Nov 21, 2020
Closed
93 tasks
@findepi findepi mentioned this issue Jul 22, 2021
Merged
@phd3 phd3 mentioned this issue Jul 27, 2021
Merged
@findepi
Copy link
Member Author

findepi commented Sep 20, 2021

Likely same as #5201, so fixed by #8504

@findepi findepi closed this as completed Sep 20, 2021
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
2 participants
@findepi @vrozov